nfs4: Add debug output functions

* Create Dump functions for several classes.
* Add 2 nfs4 kernel debugger commands.
* Incorporate the shared macros from DebugSupport.h.

The Dump functions accept an argument that determines type of output
(dprintf/kprint).  In cases where the class has an internal lock, Dump
is calling a separate _DumpLocked(), just so the output can be
done by a const function.

Change-Id: Id8da904726cb1a3ffcf9e9ac13452d1be1c9e00a
Reviewed-on: https://review.haiku-os.org/c/haiku/+/9134
Reviewed-by: waddlesplash <[email protected]>

src/add-ons/kernel/file_systems/nfs4/Debug.cpp

@@ -0,0 +1,50 @@
+/*
+ * Copyright 2025, Haiku, Inc. All rights reserved.
+ * Distributed under the terms of the MIT License.
+ */
+
+
+#include "Debug.h"
+#include "FileSystem.h"
+#include "VnodeToInode.h"
+
+
+int
+kprintf_volume(int argc, char** argv)
+{
+	if ((argc == 1) || strcmp(argv[1], "--help") == 0) {
+		kprintf("usage: nfs4 <address>\n"
+			"  address:  address of a nfs4 private volume (FileSystem)\n"
+			"  Use 'mounts' to list mounted volume ids, and 'mount <id>' to display a private "
+			"volume address.\n");
+		return 0;
+	}
+
+	FileSystem* volume = reinterpret_cast<FileSystem*>(strtoul(argv[1], NULL, 0));
+	volume->Dump(kprintf);
+
+	return 0;
+}
+
+
+int
+kprintf_inode(int argc, char** argv)
+{
+	if ((argc == 1) || strcmp(argv[1], "--help") == 0) {
+		kprintf("usage: nfs4_inode <address(es) ...>\n"
+			"  address(es):  address of one or more nfs4 private nodes (VnodeToInode), "
+			"separated by spaces\n"
+			"  Addresses can be found with the 'vnodes' command.\n");
+		return 0;
+	}
+
+	for (int i = 1; i < argc; i++) {
+		VnodeToInode* node = reinterpret_cast<VnodeToInode*>(strtoul(argv[1], NULL, 0));
+		if (node == NULL)
+			continue;
+		node->Dump(kprintf);
+		kprintf("----------\n");
+	}
+
+	return 0;
+}

src/add-ons/kernel/file_systems/nfs4/Debug.h

@@ -0,0 +1,34 @@
+/*
+ * Copyright 2025, Haiku, Inc. All rights reserved.
+ * Distributed under the terms of the MIT License.
+ */
+#ifndef NFS4_DEBUG_H
+#define NFS4_DEBUG_H
+
+
+#ifdef USER
+#define _KERNEL_MODE
+	// skip the POSIX dprintf declaration in stdio.h
+#include <stdio.h>
+#undef _KERNEL_MODE
+#endif
+
+#include <DebugSupport.h>
+
+
+#ifdef DEBUG
+#define TRACE(x...) FUNCTION(x)
+#define CALLED() FUNCTION_START()
+#else
+#define TRACE(x...)
+#define CALLED()
+#endif
+
+#if USER
+extern "C" void dprintf(const char *format, ...);
+#endif
+int kprintf_volume(int argc, char** argv);
+int kprintf_inode(int argc, char** argv);
+
+
+#endif	// NFS4_DEBUG_H

src/add-ons/kernel/file_systems/nfs4/DirectoryCache.cpp

@@ -256,6 +256,35 @@ DirectoryCache::Revalidate()
 }
 
 
+void
+DirectoryCache::Dump(void (*xprintf)(const char*, ...))
+{
+	MutexLocker locker;
+	if (xprintf != kprintf)
+		locker.SetTo(fLock, false);
+
+	_DumpLocked(xprintf);
+
+	return;
+}
+
+
+void
+DirectoryCache::_DumpLocked(void (*xprintf)(const char*, ...)) const
+{
+	xprintf("DirectoryCache::fNameCache:\n");
+
+	for (SinglyLinkedList<NameCacheEntry>::ConstIterator it = fNameCache.GetIterator();
+		const NameCacheEntry* entry = it.Next();) {
+		xprintf("\t\tino: %" B_PRIdINO "\t", entry->fNode);
+		if (entry->fName != NULL)
+			xprintf("name: %s\n", entry->fName);
+	}
+
+	return;
+}
+
+
 void
 DirectoryCache::NotifyChanges(DirectoryCacheSnapshot* oldSnapshot,
 	DirectoryCacheSnapshot* newSnapshot)

src/add-ons/kernel/file_systems/nfs4/DirectoryCache.h

@@ -15,6 +15,8 @@
 #include <util/KernelReferenceable.h>
 #include <util/SinglyLinkedList.h>
 
+#include "Debug.h"
+
 
 class Inode;
 
@@ -66,7 +68,10 @@ public:
 
 	inline	Inode*			GetInode();
 
+			void			Dump(void (*xprintf)(const char*, ...) = dprintf);
+
 	const	bigtime_t		fExpirationTime;
+
 protected:
 			void			NotifyChanges(DirectoryCacheSnapshot* oldSnapshot,
 								DirectoryCacheSnapshot* newSnapshot);
@@ -75,6 +80,8 @@ private:
 			void			_SetSnapshot(DirectoryCacheSnapshot* snapshot);
 			status_t		_LoadSnapshot(bool trash);
 
+			void			_DumpLocked(void (*xprintf)(const char*, ...)) const;
+
 			SinglyLinkedList<NameCacheEntry>	fNameCache;
 
 			DirectoryCacheSnapshot*	fDirectoryCache;

src/add-ons/kernel/file_systems/nfs4/FileInfo.cpp

@@ -13,6 +13,18 @@
 #include "Request.h"
 
 
+/*! Print the handle.
+	@pre The parent object is locked.
+*/
+void
+FileHandle::Dump(void (*xprintf)(const char*, ...)) const
+{
+	for (int i = 0; i < fSize; ++i)
+		xprintf("%d ", fData[i]);
+	xprintf("\n");
+}
+
+
 InodeName::InodeName(InodeNames* parent, const char* name)
 	:
 	fParent(parent),
@@ -87,6 +99,33 @@ InodeNames::RemoveName(InodeNames* parent, const char* name)
 }
 
 
+void
+InodeNames::Dump(void (*xprintf)(const char*, ...))
+{
+	MutexLocker locker;
+	if (xprintf != kprintf)
+		locker.SetTo(fLock, false);
+
+	_DumpLocked(xprintf);
+
+	return;
+}
+
+
+void
+InodeNames::_DumpLocked(void (*xprintf)(const char*, ...)) const
+{
+	for (SinglyLinkedList<InodeName>::ConstIterator it = fNames.GetIterator();
+		const InodeName* name = it.Next();) {
+		if (name->fName != NULL)
+			xprintf("%s ", name->fName);
+	}
+	xprintf("\n");
+
+	return;
+}
+
+
 FileInfo::FileInfo()
 	:
 	fFileId(0),

src/add-ons/kernel/file_systems/nfs4/FileInfo.h

@@ -16,6 +16,8 @@
 #include <SupportDefs.h>
 #include <util/KernelReferenceable.h>
 
+#include "Debug.h"
+
 
 #define NFS4_FHSIZE	128
 
@@ -32,6 +34,8 @@ struct FileHandle {
 	inline	bool		operator!=(const FileHandle& handle) const;
 	inline	bool		operator>(const FileHandle& handle) const;
 	inline	bool		operator<(const FileHandle& handle) const;
+
+			void		Dump(void (*xprintf)(const char*, ...) = dprintf) const;
 };
 
 struct InodeNames;
@@ -52,6 +56,10 @@ struct InodeNames : public KernelReferenceable {
 	bool						RemoveName(InodeNames* parent,
 									const char* name);
 
+	void						Dump(void (*xprintf)(const char*, ...) = dprintf);
+
+	void						_DumpLocked(void (*xprintf)(const char*, ...)) const;
+
 	mutex						fLock;
 	SinglyLinkedList<InodeName>	fNames;
 	FileHandle					fHandle;

src/add-ons/kernel/file_systems/nfs4/FileSystem.cpp

@@ -20,17 +20,6 @@
 #include "VnodeToInode.h"
 
 
-#define ERROR(x...) dprintf("nfs4: " x)
-
-#ifdef DEBUG
-#define TRACE(x...) dprintf("nfs4: " x)
-#define CALLED() dprintf("nfs4: called %s", __func__)
-#else
-#define TRACE(x...)
-#define CALLED()
-#endif
-
-
 extern RPC::ServerManager* gRPCServerManager;
 extern RPC::ProgramData* CreateNFS4Server(RPC::Server* serv);
 
@@ -522,6 +511,21 @@ FileSystem::EnsureNoCollision(ino_t newID, const FileHandle& handle)
 }
 
 
+void
+FileSystem::Dump(void (*xprintf)(const char*, ...))
+{
+	MutexLocker locker;
+	if (xprintf != kprintf)
+		locker.SetTo(fOpenLock, false);
+
+	fInoIdMap.Dump(xprintf);
+
+	_DumpLocked(xprintf);
+
+	return;
+}
+
+
 status_t
 FileSystem::_ParsePath(RequestBuilder& req, uint32& count, const char* _path)
 {
@@ -561,3 +565,21 @@ FileSystem::_ParsePath(RequestBuilder& req, uint32& count, const char* _path)
 	return B_OK;
 }
 
+
+void
+FileSystem::_DumpLocked(void (*xprintf)(const char*, ...)) const
+{
+	xprintf("fOpenFiles:\n", fOpenFiles);
+	for (DoublyLinkedList<OpenState>::ConstIterator it = fOpenFiles.GetIterator();
+		const OpenState* state = it.Next();) {
+		xprintf("\tID\t\t%" B_PRIu64 "\n", state->fInfo.fFileId);
+		xprintf("\tFileHandle\t");
+		state->fInfo.fHandle.Dump(xprintf);
+		xprintf("\tInodeNames\t");
+		state->fInfo.fNames->Dump(xprintf);
+		xprintf("\t----------\n");
+	}
+
+	return;
+}
+

src/add-ons/kernel/file_systems/nfs4/FileSystem.h

@@ -11,6 +11,7 @@
 
 #include <fs_interface.h>
 
+#include "Debug.h"
 #include "Delegation.h"
 #include "InodeIdMap.h"
 #include "NFS4Defs.h"
@@ -82,12 +83,17 @@ public:
 	inline	mutex&				CreateFileLock();
 
 			void				EnsureNoCollision(ino_t newID, const FileHandle& handle);
+
+			void				Dump(void (*xprintf)(const char*, ...) = dprintf);
+
 private:
 								FileSystem(const MountConfiguration& config);
 
 	static	status_t			_ParsePath(RequestBuilder& req, uint32& count,
 									const char* _path);
 
+			void 				_DumpLocked(void (*xprintf)(const char*, ...)) const;
+
 			mutex				fCreateFileLock;
 
 			mutex				fDelegationLock;

src/add-ons/kernel/file_systems/nfs4/Inode.cpp

@@ -1023,3 +1023,19 @@ Inode::EndAIOOp()
 		release_sem(fAIOWait);
 }
 
+
+/*! Print the ID, handle, names, and DirectoryCache if applicable.
+	@pre The parent VnodeToInode is locked.
+*/
+void
+Inode::Dump(void (*xprintf)(const char*, ...)) const
+{
+	xprintf("Inode\t%" B_PRIu64 " at %p\n", fInfo.fFileId, this);
+	xprintf("FileHandle\t");
+	fInfo.fHandle.Dump(xprintf);
+	xprintf("InodeNames\t");
+	fInfo.fNames->Dump(xprintf);
+	if (fCache != NULL)
+		fCache->Dump(xprintf);
+}
+

src/add-ons/kernel/file_systems/nfs4/Inode.h

@@ -121,6 +121,9 @@ public:
 
 	inline			void		SetStale(bool stale = true);
 	inline			bool		IsStale() const;
+
+					void		Dump(void (*xprintf)(const char*, ...) = dprintf) const;
+
 protected:
 								Inode();
 

src/add-ons/kernel/file_systems/nfs4/InodeIdMap.cpp

@@ -79,3 +79,34 @@ InodeIdMap::GetFileInfo(FileInfo* fileInfo, ino_t id)
 	return B_OK;
 }
 
+
+void
+InodeIdMap::Dump(void (*xprintf)(const char*, ...))
+{
+	MutexLocker locker;
+	if (xprintf != kprintf)
+		locker.SetTo(fLock, false);
+
+	_DumpLocked(xprintf);
+
+	return;
+}
+
+
+void
+InodeIdMap::_DumpLocked(void (*xprintf)(const char*, ...)) const
+{
+	xprintf("InodeIdMap at %p\n", this);
+	xprintf("\tino\thandle\n");
+	AVLTreeMap<ino_t, FileInfo>::ConstIterator iterator = fMap.GetIterator();
+	for (iterator.Next(); iterator.HasNext(); iterator.Next()) {
+		ino_t ino = iterator.CurrentKey();
+		xprintf("\t%" B_PRIdINO "\t", ino);
+		const FileInfo* fileInfo = iterator.CurrentValuePointer();
+		if (fileInfo != NULL)
+			fileInfo->fHandle.Dump(xprintf);
+	}
+
+	return;
+}
+

src/add-ons/kernel/file_systems/nfs4/InodeIdMap.h

@@ -31,6 +31,10 @@ public:
 			status_t						RemoveEntry(ino_t id);
 			status_t						GetFileInfo(FileInfo* fileInfo,
 												ino_t id);
+			void							Dump(void (*xprintf)(const char*, ...) = dprintf);
+
+private:
+			void							_DumpLocked(void (*xprintf)(const char*, ...)) const;
 
 private:
 			AVLTreeMap<ino_t, FileInfo>		fMap;

src/add-ons/kernel/file_systems/nfs4/Jamfile

@@ -1,11 +1,15 @@
 SubDir HAIKU_TOP src add-ons kernel file_systems nfs4 ;
 
 UsePrivateKernelHeaders ;
-UsePrivateHeaders shared ;
+UsePrivateHeaders file_systems shared ;
+
+DEFINES += DEBUG_APP="\\\"nfs4\\\"" ;
 
 KernelAddon nfs4 :
 	Cookie.cpp
 	Connection.cpp
+	Debug.cpp
+	DebugSupport.cpp
 	Delegation.cpp
 	DirectoryCache.cpp
 	FileInfo.cpp
@@ -40,5 +44,8 @@ KernelAddon nfs4 :
 	XDR.cpp
 ;
 
+SEARCH on [ FGristFiles DebugSupport.cpp ]
+	+= [ FDirName $(HAIKU_TOP) src add-ons kernel file_systems shared ] ;
+
 SubInclude HAIKU_TOP src add-ons kernel file_systems nfs4 idmapper ;
 

src/add-ons/kernel/file_systems/nfs4/NFS4Defs.h

@@ -14,10 +14,6 @@
 
 #include <SupportDefs.h>
 
-#ifdef USER
-extern "C" void dprintf(const char *format,...);
-#endif
-
 
 enum Procedure {
 	ProcNull		= 0,

src/add-ons/kernel/file_systems/nfs4/ReplyInterpreter.cpp

@@ -17,17 +17,6 @@
 #include "Cookie.h"
 
 
-#define ERROR(x...) dprintf("nfs4: " x)
-
-#ifdef DEBUG
-#define TRACE(x...) dprintf("nfs4: " x)
-#define CALLED() dprintf("nfs4: called %s", __func__)
-#else
-#define TRACE(x...)
-#define CALLED()
-#endif
-
-
 static status_t
 ProcessStream(RPC::Reply* reply, const char* callName)
 {

src/add-ons/kernel/file_systems/nfs4/VnodeToInode.cpp

@@ -51,3 +51,21 @@ VnodeToInode::Unlink(InodeNames* parent, const char* name)
 	return false;
 }
 
+
+void
+VnodeToInode::Dump(void (*xprintf)(const char*, ...))
+{
+	xprintf("VTI\t%" B_PRIdINO " at %p\n", fID);
+
+	ReadLocker locker;
+	if (xprintf != kprintf)
+		locker.SetTo(fLock, false);
+
+	if (fInode != NULL)
+		fInode->Dump(xprintf);
+	else
+		xprintf("NULL Inode");
+
+	return;
+}
+

src/add-ons/kernel/file_systems/nfs4/VnodeToInode.h

@@ -34,6 +34,8 @@ public:
 	inline	ino_t		ID() const;
 
 	inline	bool		IsRoot() const;
+
+			void		Dump(void (*xprintf)(const char*, ...) = dprintf);
 private:
 			ino_t		fID;
 			rw_lock		fLock;

src/add-ons/kernel/file_systems/nfs4/kernel_interface.cpp

@@ -25,16 +25,6 @@
 #include "WorkQueue.h"
 
 
-#define ERROR(format, args...) \
-	dprintf("nfs4: %s()" format "\n", __func__ , ##args)
-
-#ifdef DEBUG
-#define TRACE(format, args...) \
-	dprintf("nfs4: %s()" format "\n", __func__ , ##args)
-#else
-#define TRACE(x...)	(void)0
-#endif
-
 extern fs_volume_ops gNFSv4VolumeOps;
 extern fs_vnode_ops gNFSv4VnodeOps;
 
@@ -1403,6 +1393,8 @@ nfs4_release_lock(fs_volume* volume, fs_vnode* vnode, void* _cookie,
 status_t
 nfs4_init()
 {
+	init_debugging();
+
 	gRPCServerManager = new(std::nothrow) RPC::ServerManager;
 	if (gRPCServerManager == NULL)
 		return B_NO_MEMORY;
@@ -1418,6 +1410,11 @@ nfs4_init()
 		return B_NO_MEMORY;
 	}
 
+#ifdef _KERNEL_MODE
+	add_debugger_command("nfs4", kprintf_volume, "dump an nfs4 volume");
+	add_debugger_command("nfs4_inode", kprintf_inode, "dump an nfs4 inode");
+#endif // _KERNEL_MODE
+
 	return B_OK;
 }
 
@@ -1425,6 +1422,8 @@ nfs4_init()
 status_t
 nfs4_uninit()
 {
+	exit_debugging();
+
 	RPC::CallbackServer::ShutdownAll();
 
 	delete gIdMapper;
@@ -1433,6 +1432,11 @@ nfs4_uninit()
 
 	mutex_destroy(&gIdMapperLock);
 
+#ifdef _KERNEL_MODE
+	remove_debugger_command("nfs4", kprintf_volume);
+	remove_debugger_command("nfs4_inode", kprintf_inode);
+#endif // _KERNEL_MODE
+
 	return B_OK;
 }
 

src/tests/add-ons/kernel/file_systems/userlandfs/nfs4/Jamfile

@@ -8,6 +8,8 @@ SEARCH_SOURCE += $(nfs4Top) ;
 {
 	local defines =
 		USER=1
+		DEBUG_APP="\\\"userlandfs_server\\\""
+			# with this setting, output of the driver will be integrated with that of the server when DEBUG_PRINT is defined for both
 	;
 
 	defines = [ FDefines $(defines) ] ;
@@ -15,12 +17,14 @@ SEARCH_SOURCE += $(nfs4Top) ;
 }
 
 UsePrivateKernelHeaders ;
-UsePrivateHeaders shared ;
+UsePrivateHeaders file_systems shared ;
 
 Addon <userland>nfs4
 	:
 	Cookie.cpp
 	Connection.cpp
+	Debug.cpp
+	DebugSupport.cpp
 	Delegation.cpp
 	DirectoryCache.cpp
 	FileInfo.cpp
@@ -59,4 +63,7 @@ Addon <userland>nfs4
 	[ TargetLibsupc++ ]
 ;
 
+SEARCH on [ FGristFiles DebugSupport.cpp ]
+	+= [ FDirName $(HAIKU_TOP) src add-ons kernel file_systems shared ] ;
+
 SubInclude HAIKU_TOP src add-ons kernel file_systems nfs4 idmapper ;