Support setting a logger for fuse errors (but not other debug info).

For GoogleCloudPlatform/gcsfuse#60.

connection.go

@@ -40,7 +40,8 @@ var fTraceByPID = flag.Bool(
 
 // A connection to the fuse kernel process.
 type Connection struct {
-	logger      *log.Logger
+	debugLogger *log.Logger
+	errorLogger *log.Logger
 	wrapped     *bazilfuse.Conn
 	opsInFlight sync.WaitGroup
 
@@ -68,10 +69,12 @@ type Connection struct {
 // result. You must call c.close() eventually.
 func newConnection(
 	parentCtx context.Context,
-	logger *log.Logger,
+	debugLogger *log.Logger,
+	errorLogger *log.Logger,
 	wrapped *bazilfuse.Conn) (c *Connection, err error) {
 	c = &Connection{
-		logger:      logger,
+		debugLogger: debugLogger,
+		errorLogger: errorLogger,
 		wrapped:     wrapped,
 		parentCtx:   parentCtx,
 		cancelFuncs: make(map[bazilfuse.RequestID]func()),
@@ -83,7 +86,7 @@ func newConnection(
 
 // Log information for an operation with the given ID. calldepth is the depth
 // to use when recovering file:line information with runtime.Caller.
-func (c *Connection) log(
+func (c *Connection) debugLog(
 	opID uint32,
 	calldepth int,
 	format string,
@@ -108,7 +111,7 @@ func (c *Connection) log(
 		fmt.Sprintf(format, v...))
 
 	// Print it.
-	c.logger.Println(msg)
+	c.debugLogger.Println(msg)
 }
 
 // LOCKS_EXCLUDED(c.mu)
@@ -316,13 +319,13 @@ func (c *Connection) ReadOp() (op fuseops.Op, err error) {
 		c.nextOpID++
 
 		// Log the receipt of the operation.
-		c.log(opID, 1, "<- %v", bfReq)
+		c.debugLog(opID, 1, "<- %v", bfReq)
 
 		// Special case: responding to statfs is required to make mounting work on
 		// OS X. We don't currently expose the capability for the file system to
 		// intercept this.
 		if statfsReq, ok := bfReq.(*bazilfuse.StatfsRequest); ok {
-			c.log(opID, 1, "-> (Statfs) OK")
+			c.debugLog(opID, 1, "-> (Statfs) OK")
 			statfsReq.Respond(&bazilfuse.StatfsResponse{})
 			continue
 		}
@@ -336,13 +339,19 @@ func (c *Connection) ReadOp() (op fuseops.Op, err error) {
 		// Set up op dependencies.
 		opCtx := c.beginOp(bfReq)
 
-		logForOp := func(calldepth int, format string, v ...interface{}) {
-			c.log(opID, calldepth+1, format, v...)
+		debugLogForOp := func(calldepth int, format string, v ...interface{}) {
+			c.debugLog(opID, calldepth+1, format, v...)
 		}
 
 		finished := func(err error) { c.finishOp(bfReq) }
 
-		op = fuseops.Convert(opCtx, bfReq, logForOp, finished)
+		op = fuseops.Convert(
+			opCtx,
+			bfReq,
+			debugLogForOp,
+			c.errorLogger,
+			finished)
+
 		return
 	}
 }

debug.go

@@ -28,12 +28,12 @@ var fEnableDebug = flag.Bool(
 	false,
 	"Write FUSE debugging messages to stderr.")
 
-var gLogger *log.Logger
-var gLoggerOnce sync.Once
+var gDebugLogger *log.Logger
+var gDebugLoggerOnce sync.Once
 
-func initLogger() {
+func initDebugDebugLogger() {
 	if !flag.Parsed() {
-		panic("initLogger called before flags available.")
+		panic("initDebugDebugLogger called before flags available.")
 	}
 
 	var writer io.Writer = ioutil.Discard
@@ -42,10 +42,10 @@ func initLogger() {
 	}
 
 	const flags = log.Ldate | log.Ltime | log.Lmicroseconds
-	gLogger = log.New(writer, "", flags)
+	gDebugLogger = log.New(writer, "", flags)
 }
 
-func getLogger() *log.Logger {
-	gLoggerOnce.Do(initLogger)
-	return gLogger
+func getDebugLogger() *log.Logger {
+	gDebugLoggerOnce.Do(initDebugDebugLogger)
+	return gDebugLogger
 }

fuseops/common_op.go

@@ -16,6 +16,7 @@ package fuseops
 
 import (
 	"fmt"
+	"log"
 	"reflect"
 	"strings"
 
@@ -46,9 +47,12 @@ type commonOp struct {
 	// The underlying bazilfuse request for this op.
 	bazilReq bazilfuse.Request
 
-	// A function that can be used to log information about the op. The first
-	// argument is a call depth.
-	log func(int, string, ...interface{})
+	// A function that can be used to log debug information about the op. The
+	// first argument is a call depth.
+	debugLog func(int, string, ...interface{})
+
+	// A logger to be used for logging exceptional errors.
+	errorLogger *log.Logger
 
 	// A function that is invoked with the error given to Respond, for use in
 	// closing off traces and reporting back to the connection.
@@ -76,13 +80,15 @@ func (o *commonOp) init(
 	ctx context.Context,
 	op internalOp,
 	bazilReq bazilfuse.Request,
-	log func(int, string, ...interface{}),
+	debugLog func(int, string, ...interface{}),
+	errorLogger *log.Logger,
 	finished func(error)) {
 	// Initialize basic fields.
 	o.ctx = ctx
 	o.op = op
 	o.bazilReq = bazilReq
-	o.log = log
+	o.debugLog = debugLog
+	o.errorLogger = errorLogger
 	o.finished = finished
 
 	// Set up a trace span for this op.
@@ -111,7 +117,7 @@ func (o *commonOp) Context() context.Context {
 
 func (o *commonOp) Logf(format string, v ...interface{}) {
 	const calldepth = 2
-	o.log(calldepth, format, v...)
+	o.debugLog(calldepth, format, v...)
 }
 
 func (o *commonOp) Respond(err error) {
@@ -130,6 +136,11 @@ func (o *commonOp) Respond(err error) {
 		o.op.ShortDesc(),
 		err)
 
+	o.errorLogger.Printf(
+		"(%s) error: %v",
+		o.op.ShortDesc(),
+		err)
+
 	// Send a response to the kernel.
 	o.bazilReq.RespondError(err)
 }

fuseops/convert.go

@@ -15,6 +15,7 @@
 package fuseops
 
 import (
+	"log"
 	"time"
 
 	"golang.org/x/net/context"
@@ -34,7 +35,8 @@ import (
 func Convert(
 	opCtx context.Context,
 	r bazilfuse.Request,
-	logForOp func(int, string, ...interface{}),
+	debugLogForOp func(int, string, ...interface{}),
+	errorLogger *log.Logger,
 	finished func(error)) (o Op) {
 	var co *commonOp
 
@@ -239,7 +241,13 @@ func Convert(
 		co = &to.commonOp
 	}
 
-	co.init(opCtx, io, r, logForOp, finished)
+	co.init(
+		opCtx,
+		io,
+		r,
+		debugLogForOp,
+		errorLogger,
+		finished)
 
 	o = io
 	return

mounted_file_system.go

@@ -16,6 +16,8 @@ package fuse
 
 import (
 	"fmt"
+	"io/ioutil"
+	"log"
 	"runtime"
 
 	"github.com/jacobsa/bazilfuse"
@@ -75,6 +77,11 @@ type MountConfig struct {
 	// chtimes, etc. will fail.
 	ReadOnly bool
 
+	// A logger to use for logging errors. All errors are logged, with the
+	// exception of a few blacklisted errors that are expected. If nil, no error
+	// logging is performed.
+	ErrorLogger *log.Logger
+
 	// OS X only.
 	//
 	// Normally on OS X we mount with the novncache option
@@ -148,7 +155,7 @@ func Mount(
 	dir string,
 	server Server,
 	config *MountConfig) (mfs *MountedFileSystem, err error) {
-	logger := getLogger()
+	debugLogger := getDebugLogger()
 
 	// Initialize the struct.
 	mfs = &MountedFileSystem{
@@ -157,7 +164,7 @@ func Mount(
 	}
 
 	// Open a bazilfuse connection.
-	logger.Println("Opening a bazilfuse connection.")
+	debugLogger.Println("Opening a bazilfuse connection.")
 	bfConn, err := bazilfuse.Mount(mfs.dir, config.bazilfuseOptions()...)
 	if err != nil {
 		err = fmt.Errorf("bazilfuse.Mount: %v", err)
@@ -170,8 +177,19 @@ func Mount(
 		opContext = context.Background()
 	}
 
+	// Create a /dev/null error logger if necessary.
+	errorLogger := config.ErrorLogger
+	if errorLogger == nil {
+		errorLogger = log.New(ioutil.Discard, "", 0)
+	}
+
 	// Create our own Connection object wrapping it.
-	connection, err := newConnection(opContext, logger, bfConn)
+	connection, err := newConnection(
+		opContext,
+		debugLogger,
+		errorLogger,
+		bfConn)
+
 	if err != nil {
 		bfConn.Close()
 		err = fmt.Errorf("newConnection: %v", err)