fuse: increase signal/noise in log messages

- use tA=...s instead of `A...` or `AttrValid=...` for time(Attr valid);
- use tE=...s instead of `EntryValid` for time(Entry valid);
- use iX instead of `NodeId: X` for inode X;
- use gX instead of `Generation=X` for generation X;
- use `[<off> +<size>)` instead of `off <off> sz <sz>`;

- use

        rx uniq: Op iX opargs
        tx uniq: status reply...

  instead of

        Dispatch uniq: Op NodeId: X opargs
        Serialize uniq: Op code: status reply...

  for received/replied messages;

- use `["file1", "file2"]` instead of `names: [file1, file2]` for filenames.

- use `xb` instead of `x bytes`

- for replied data, also log data content, but only up to first 8 bytes.
  This does not flood the log, but at the same time makes filesystem
  diagnostics easier.

fuse/print.go

@@ -198,19 +198,24 @@ func (me *FlushIn) string() string {
 
 func (me *AttrOut) string() string {
 	return fmt.Sprintf(
-		"{A%d.%09d %v}",
-		me.AttrValid, me.AttrValidNsec, &me.Attr)
+		"{tA=%gs %v}",
+		ft(me.AttrValid, me.AttrValidNsec), &me.Attr)
+}
+
+// ft converts (seconds , nanoseconds) -> float(seconds)
+func ft(tsec uint64, tnsec uint32) float64 {
+	return float64(tsec) + float64(tnsec)*1E-9
 }
 
 // Returned by LOOKUP
 func (me *EntryOut) string() string {
-	return fmt.Sprintf("{NodeId: %d Generation=%d EntryValid=%d.%03d AttrValid=%d.%03d Attr=%v}",
-		me.NodeId, me.Generation, me.EntryValid, me.EntryValidNsec/1000000,
-		me.AttrValid, me.AttrValidNsec/1000000, &me.Attr)
+	return fmt.Sprintf("{i%d g%d tE=%gs tA=%gs %v}",
+		me.NodeId, me.Generation, ft(me.EntryValid, me.EntryValidNsec),
+		ft(me.AttrValid, me.AttrValidNsec), &me.Attr)
 }
 
 func (me *CreateOut) string() string {
-	return fmt.Sprintf("{NodeId: %d Generation=%d %v %v}", me.NodeId, me.Generation, &me.EntryOut, &me.OpenOut)
+	return fmt.Sprintf("{i%d g%d %v %v}", me.NodeId, me.Generation, &me.EntryOut, &me.OpenOut)
 }
 
 func (me *StatfsOut) string() string {
@@ -225,7 +230,7 @@ func (o *NotifyInvalEntryOut) string() string {
 }
 
 func (o *NotifyInvalInodeOut) string() string {
-	return fmt.Sprintf("{ino %d off %d sz %d}", o.Ino, o.Off, o.Length)
+	return fmt.Sprintf("{i%d [%d +%d)}", o.Ino, o.Off, o.Length)
 }
 
 func (o *NotifyInvalDeleteOut) string() string {
@@ -233,19 +238,19 @@ func (o *NotifyInvalDeleteOut) string() string {
 }
 
 func (o *NotifyStoreOut) string() string {
-	return fmt.Sprintf("{nodeid %d off %d sz %d}", o.Nodeid, o.Offset, o.Size)
+	return fmt.Sprintf("{i%d [%d +%d)}", o.Nodeid, o.Offset, o.Size)
 }
 
 func (o *NotifyRetrieveOut) string() string {
-	return fmt.Sprintf("{notifyUnique %d nodeid %d off %d sz %d}", o.NotifyUnique, o.Nodeid, o.Offset, o.Size)
+	return fmt.Sprintf("{> %d: i%d [%d +%d)}", o.NotifyUnique, o.Nodeid, o.Offset, o.Size)
 }
 
 func (i *NotifyRetrieveIn) string() string {
-	return fmt.Sprintf("{off %d sz %d}", i.Offset, i.Size)
+	return fmt.Sprintf("{[%d +%d)}", i.Offset, i.Size)
 }
 
 func (f *FallocateIn) string() string {
-	return fmt.Sprintf("{Fh %d off %d sz %d mod 0%o}",
+	return fmt.Sprintf("{Fh %d [%d +%d) mod 0%o}",
 		f.Fh, f.Offset, f.Length, f.Mode)
 }
 

fuse/print_darwin.go

@@ -19,14 +19,14 @@ func (a *Attr) string() string {
 		"{M0%o SZ=%d L=%d "+
 			"%d:%d "+
 			"%d %d:%d "+
-			"A %d.%09d "+
-			"M %d.%09d "+
-			"C %d.%09d}",
+			"A %f "+
+			"M %f "+
+			"C %f}",
 		a.Mode, a.Size, a.Nlink,
 		a.Uid, a.Gid,
 		a.Blocks,
-		a.Rdev, a.Ino, a.Atime, a.Atimensec, a.Mtime, a.Mtimensec,
-		a.Ctime, a.Ctimensec)
+		a.Rdev, a.Ino, ft(a.Atime, a.Atimensec), ft(a.Mtime, a.Mtimensec),
+		ft(a.Ctime, a.Ctimensec))
 }
 
 func (me *CreateIn) string() string {
@@ -42,13 +42,13 @@ func (me *MknodIn) string() string {
 }
 
 func (me *ReadIn) string() string {
-	return fmt.Sprintf("{Fh %d off %d sz %d %s}",
+	return fmt.Sprintf("{Fh %d [%d +%d) %s}",
 		me.Fh, me.Offset, me.Size,
 		FlagString(readFlagNames, int64(me.ReadFlags), ""))
 }
 
 func (me *WriteIn) string() string {
-	return fmt.Sprintf("{Fh %d off %d sz %d %s}",
+	return fmt.Sprintf("{Fh %d [%d +%d) %s}",
 		me.Fh, me.Offset, me.Size,
 		FlagString(writeFlagNames, int64(me.WriteFlags), ""))
 }

fuse/print_linux.go

@@ -21,14 +21,14 @@ func (a *Attr) string() string {
 		"{M0%o SZ=%d L=%d "+
 			"%d:%d "+
 			"B%d*%d i%d:%d "+
-			"A %d.%09d "+
-			"M %d.%09d "+
-			"C %d.%09d}",
+			"A %f "+
+			"M %f "+
+			"C %f}",
 		a.Mode, a.Size, a.Nlink,
 		a.Uid, a.Gid,
 		a.Blocks, a.Blksize,
-		a.Rdev, a.Ino, a.Atime, a.Atimensec, a.Mtime, a.Mtimensec,
-		a.Ctime, a.Ctimensec)
+		a.Rdev, a.Ino, ft(a.Atime, a.Atimensec), ft(a.Mtime, a.Mtimensec),
+		ft(a.Ctime, a.Ctimensec))
 }
 
 func (me *CreateIn) string() string {
@@ -46,7 +46,7 @@ func (me *MknodIn) string() string {
 }
 
 func (me *ReadIn) string() string {
-	return fmt.Sprintf("{Fh %d off %d sz %d %s L %d %s}",
+	return fmt.Sprintf("{Fh %d [%d +%d) %s L %d %s}",
 		me.Fh, me.Offset, me.Size,
 		FlagString(readFlagNames, int64(me.ReadFlags), ""),
 		me.LockOwner,
@@ -54,7 +54,7 @@ func (me *ReadIn) string() string {
 }
 
 func (me *WriteIn) string() string {
-	return fmt.Sprintf("{Fh %d off %d sz %d %s L %d %s}",
+	return fmt.Sprintf("{Fh %d [%d +%d) %s L %d %s}",
 		me.Fh, me.Offset, me.Size,
 		FlagString(writeFlagNames, int64(me.WriteFlags), ""),
 		me.LockOwner,

fuse/request.go

@@ -73,23 +73,23 @@ func (r *request) clear() {
 }
 
 func (r *request) InputDebug() string {
-	val := " "
+	val := ""
 	if r.handler.DecodeIn != nil {
-		val = fmt.Sprintf(" data: %v ", Print(r.handler.DecodeIn(r.inData)))
+		val = fmt.Sprintf("%v ", Print(r.handler.DecodeIn(r.inData)))
 	}
 
 	names := ""
 	if r.filenames != nil {
-		names = fmt.Sprintf("names: %v", r.filenames)
+		names = fmt.Sprintf("%q", r.filenames)
 	}
 
 	if len(r.arg) > 0 {
-		names += fmt.Sprintf(" %d bytes", len(r.arg))
+		names += fmt.Sprintf(" %db", len(r.arg))
 	}
 
-	return fmt.Sprintf("Dispatch %d: %s, NodeId: %v.%v%v",
-		r.inHeader.Unique, operationName(r.inHeader.Opcode),
-		r.inHeader.NodeId, val, names)
+	return fmt.Sprintf("rx %d: %s i%d %s%s",
+		r.inHeader.Unique, operationName(r.inHeader.Opcode), r.inHeader.NodeId,
+		val, names)
 }
 
 func (r *request) OutputDebug() string {
@@ -112,14 +112,25 @@ func (r *request) OutputDebug() string {
 			spl := ""
 			if r.fdData != nil {
 				spl = " (fd data)"
+			} else {
+				l := len(r.flatData)
+				s := ""
+				if l > 8 {
+					l = 8
+					s = "..."
+				}
+				spl = fmt.Sprintf(" %q%s", r.flatData[:l], s)
 			}
-			flatStr = fmt.Sprintf(" %d bytes data%s", r.flatDataSize(), spl)
+			flatStr = fmt.Sprintf(" %db data%s", r.flatDataSize(), spl)
 		}
 	}
 
-	return fmt.Sprintf("Serialize %d: %s code: %v value: %v%v",
-		r.inHeader.Unique, operationName(r.inHeader.Opcode), r.status,
-		dataStr, flatStr)
+	extraStr := dataStr + flatStr
+	if extraStr != "" {
+		extraStr = ", " + extraStr
+	}
+	return fmt.Sprintf("tx %d:     %v%s",
+		r.inHeader.Unique, r.status, extraStr)
 }
 
 // setInput returns true if it takes ownership of the argument, false if not.