Skip to contentSkip to conversation

Trailing garbage in event tracing output

DISCUSSION Brian Candler 2 participants 2 messages Feb 2, 2012 XFS filesystem

lore
Share & tools
lore
#0 lore raw

Just a minor issue, but when I did some XFS tracing using the instructions at http://lwn.net/Articles/341899/ I found that there was trailing garbage in the filenames logged in xfs_lookup. Example:

...

        bonnie++-26179 [000] 322388.834204: xfs_iunlock: dev 8:32 ino 0xfe1e6 flags ILOCK_SHARED caller xfs_free_eofblocks
        bonnie++-26179 [000] 322388.834212: xfs_lookup: dev 8:32 dp ino 0xfb50d name 000000295aSl688>v??*N
        bonnie++-26179 [000] 322388.834213: xfs_ilock: dev 8:32 ino 0xfb50d flags ILOCK_SHARED caller xfs_ilock_map_shared

...

(where I think the real filename was "000000295aSl688"). I would guess the logger is expecting null-terminated strings but they aren't.

This is with the stock kernel from Ubuntu 11.10 server x86_64:
Linux storage1 3.0.0-15-server #26-Ubuntu SMP Fri Jan 20 19:07:39 UTC 2012 x86_64 x86_64 x86_64 GNU/Linux

Regards,

Brian.

_______________________________________________
xfs mailing list
[email protected]
http://oss.sgi.com/mailman/listinfo/xfs

#1 lore raw
Quoted 6 lines · Brian Candler

Just a minor issue, but when I did some XFS tracing using the instructions at http://lwn.net/Articles/341899/ I found that there was trailing garbage in the filenames logged in xfs_lookup. Example:

(where I think the real filename was "000000295aSl688"). I would guess the logger is expecting null-terminated strings but they aren't.

That's indeed the case. See the attched patch to fix the issue. To apply it against the 3.0 kernel you'll probably have to edit it to remove "linux-2.6/" directory in the filenames.

From: Christoph Hellwig <[email protected]>
Subject: xfs: trace xfs_name strings correctly

Strings store in an xfs_name structure are often not NUL terminated, print them using the correct printf specifiers that make use of the string length store in the xfs_name structure.

fs/xfs/xfs_trace.h +13 -3
Index: xfs/fs/xfs/xfs_trace.h
===================================================================
@@ -627,16 +627,19 @@ DECLARE_EVENT_CLASS(xfs_namespace_class,
 	TP_STRUCT__entry(
 		__field(dev_t, dev)
 		__field(xfs_ino_t, dp_ino)
+		__field(int, namelen)
 		__dynamic_array(char, name, name->len)
 	),
 	TP_fast_assign(
 		__entry->dev = VFS_I(dp)->i_sb->s_dev;
 		__entry->dp_ino = dp->i_ino;
+		__entry->namelen = name->len;
 		memcpy(__get_str(name), name->name, name->len);
 	),
-	TP_printk("dev %d:%d dp ino 0x%llx name %s",
+	TP_printk("dev %d:%d dp ino 0x%llx name %.*s",
 		  MAJOR(__entry->dev), MINOR(__entry->dev),
 		  __entry->dp_ino,
+		  __entry->namelen,
 		  __get_str(name))
 )
 
@@ -658,6 +661,8 @@ TRACE_EVENT(xfs_rename,
 		__field(dev_t, dev)
 		__field(xfs_ino_t, src_dp_ino)
 		__field(xfs_ino_t, target_dp_ino)
+		__field(int, src_namelen)
+		__field(int, target_namelen)
 		__dynamic_array(char, src_name, src_name->len)
 		__dynamic_array(char, target_name, target_name->len)
 	),
@@ -665,15 +670,20 @@ TRACE_EVENT(xfs_rename,
 		__entry->dev = VFS_I(src_dp)->i_sb->s_dev;
 		__entry->src_dp_ino = src_dp->i_ino;
 		__entry->target_dp_ino = target_dp->i_ino;
+		__entry->src_namelen = src_name->len;
+		__entry->target_namelen = target_name->len;
 		memcpy(__get_str(src_name), src_name->name, src_name->len);
-		memcpy(__get_str(target_name), target_name->name, target_name->len);
+		memcpy(__get_str(target_name), target_name->name,
+			target_name->len);
 	),
 	TP_printk("dev %d:%d src dp ino 0x%llx target dp ino 0x%llx"
-		  " src name %s target name %s",
+		  " src name %.*s target name %.*s",
 		  MAJOR(__entry->dev), MINOR(__entry->dev),
 		  __entry->src_dp_ino,
 		  __entry->target_dp_ino,
+		  __entry->src_namelen,
 		  __get_str(src_name),
+		  __entry->target_namelen,
 		  __get_str(target_name))
 )
 

_______________________________________________
xfs mailing list
[email protected]
http://oss.sgi.com/mailman/listinfo/xfs