diff --git a/components/engine/daemon/graphdriver/devmapper/deviceset.go b/components/engine/daemon/graphdriver/devmapper/deviceset.go index 696e56fb4d..a7e06e1f95 100644 --- a/components/engine/daemon/graphdriver/devmapper/deviceset.go +++ b/components/engine/daemon/graphdriver/devmapper/deviceset.go @@ -34,17 +34,13 @@ import ( ) var ( - defaultDataLoopbackSize int64 = 100 * 1024 * 1024 * 1024 - defaultMetaDataLoopbackSize int64 = 2 * 1024 * 1024 * 1024 - defaultBaseFsSize uint64 = 10 * 1024 * 1024 * 1024 - defaultThinpBlockSize uint32 = 128 // 64K = 128 512b sectors - defaultUdevSyncOverride = false - maxDeviceID = 0xffffff // 24 bit, pool limit - deviceIDMapSz = (maxDeviceID + 1) / 8 - // We retry device removal so many a times that even error messages - // will fill up console during normal operation. So only log Fatal - // messages by default. - logLevel = devicemapper.LogLevelFatal + defaultDataLoopbackSize int64 = 100 * 1024 * 1024 * 1024 + defaultMetaDataLoopbackSize int64 = 2 * 1024 * 1024 * 1024 + defaultBaseFsSize uint64 = 10 * 1024 * 1024 * 1024 + defaultThinpBlockSize uint32 = 128 // 64K = 128 512b sectors + defaultUdevSyncOverride = false + maxDeviceID = 0xffffff // 24 bit, pool limit + deviceIDMapSz = (maxDeviceID + 1) / 8 driverDeferredRemovalSupport = false enableDeferredRemoval = false enableDeferredDeletion = false @@ -1272,26 +1268,6 @@ func setCloseOnExec(name string) { } } -// DMLog implements logging using DevMapperLogger interface. -func (devices *DeviceSet) DMLog(level int, file string, line int, dmError int, message string) { - // By default libdm sends us all the messages including debug ones. - // We need to filter out messages here and figure out which one - // should be printed. - if level > logLevel { - return - } - - // FIXME(vbatts) push this back into ./pkg/devicemapper/ - if level <= devicemapper.LogLevelErr { - logrus.Errorf("libdevmapper(%d): %s:%d (%d) %s", level, file, line, dmError, message) - } else if level <= devicemapper.LogLevelInfo { - logrus.Infof("libdevmapper(%d): %s:%d (%d) %s", level, file, line, dmError, message) - } else { - // FIXME(vbatts) push this back into ./pkg/devicemapper/ - logrus.Debugf("libdevmapper(%d): %s:%d (%d) %s", level, file, line, dmError, message) - } -} - func major(device uint64) uint64 { return (device >> 8) & 0xfff } @@ -1689,9 +1665,6 @@ func (devices *DeviceSet) enableDeferredRemovalDeletion() error { } func (devices *DeviceSet) initDevmapper(doInit bool) (retErr error) { - // give ourselves to libdm as a log handler - devicemapper.LogInit(devices) - if err := devices.enableDeferredRemovalDeletion(); err != nil { return err } @@ -2804,6 +2777,18 @@ func NewDeviceSet(root string, doInit bool, options []string, uidMaps, gidMaps [ return nil, errors.New("dm.thinp_autoextend_threshold must be greater than 0 and less than 100") } lvmSetupConfig.AutoExtendThreshold = per + case "dm.libdm_log_level": + level, err := strconv.ParseInt(val, 10, 32) + if err != nil { + return nil, errors.Wrapf(err, "could not parse `dm.libdm_log_level=%s`", val) + } + if level < devicemapper.LogLevelFatal || level > devicemapper.LogLevelDebug { + return nil, errors.Errorf("dm.libdm_log_level must be in range [%d,%d]", devicemapper.LogLevelFatal, devicemapper.LogLevelDebug) + } + // Register a new logging callback with the specified level. + devicemapper.LogInit(devicemapper.DefaultLogger{ + Level: int(level), + }) default: return nil, fmt.Errorf("devmapper: Unknown option %s\n", key) } diff --git a/components/engine/pkg/devicemapper/devmapper.go b/components/engine/pkg/devicemapper/devmapper.go index 5bd7366f3b..f331970802 100644 --- a/components/engine/pkg/devicemapper/devmapper.go +++ b/components/engine/pkg/devicemapper/devmapper.go @@ -13,11 +13,6 @@ import ( "golang.org/x/sys/unix" ) -// DevmapperLogger defines methods for logging with devicemapper. -type DevmapperLogger interface { - DMLog(level int, file string, line int, dmError int, message string) -} - const ( deviceCreate TaskType = iota deviceReload @@ -264,19 +259,6 @@ func UdevWait(cookie *uint) error { return nil } -// LogInitVerbose is an interface to initialize the verbose logger for the device mapper library. -func LogInitVerbose(level int) { - DmLogInitVerbose(level) -} - -var dmLogger DevmapperLogger - -// LogInit initializes the logger for the device mapper library. -func LogInit(logger DevmapperLogger) { - dmLogger = logger - LogWithErrnoInit() -} - // SetDevDir sets the dev folder for the device mapper library (usually /dev). func SetDevDir(dir string) error { if res := DmSetDevDir(dir); res != 1 { diff --git a/components/engine/pkg/devicemapper/devmapper_log.go b/components/engine/pkg/devicemapper/devmapper_log.go index 7dd0c60891..098d2405ed 100644 --- a/components/engine/pkg/devicemapper/devmapper_log.go +++ b/components/engine/pkg/devicemapper/devmapper_log.go @@ -5,17 +5,45 @@ package devicemapper import "C" import ( + "fmt" "strings" + + "github.com/Sirupsen/logrus" ) +// DevmapperLogger defines methods required to register as a callback for +// logging events recieved from devicemapper. Note that devicemapper will send +// *all* logs regardless to callbacks (including debug logs) so it's +// recommended to not spam the console with the outputs. +type DevmapperLogger interface { + // DMLog is the logging callback containing all of the information from + // devicemapper. The interface is identical to the C libdm counterpart. + DMLog(level int, file string, line int, dmError int, message string) +} + +// dmLogger is the current logger in use that is being forwarded our messages. +var dmLogger DevmapperLogger + +// LogInit changes the logging callback called after processing libdm logs for +// error message information. The default logger simply forwards all logs to +// logrus. Calling LogInit(nil) disables the calling of callbacks. +func LogInit(logger DevmapperLogger) { + dmLogger = logger +} + // Due to the way cgo works this has to be in a separate file, as devmapper.go has // definitions in the cgo block, which is incompatible with using "//export" -// DevmapperLogCallback exports the devmapper log callback for cgo. +// DevmapperLogCallback exports the devmapper log callback for cgo. Note that +// because we are using callbacks, this function will be called for *every* log +// in libdm (even debug ones because there's no way of setting the verbosity +// level for an external logging callback). //export DevmapperLogCallback -func DevmapperLogCallback(level C.int, file *C.char, line C.int, dmErrnoOrClass C.int, message *C.char) { +func DevmapperLogCallback(level C.int, file *C.char, line, dmErrnoOrClass C.int, message *C.char) { msg := C.GoString(message) - if level < 7 { + + // Track what errno libdm saw, because the library only gives us 0 or 1. + if level < LogLevelDebug { if strings.Contains(msg, "busy") { dmSawBusy = true } @@ -33,3 +61,61 @@ func DevmapperLogCallback(level C.int, file *C.char, line C.int, dmErrnoOrClass dmLogger.DMLog(int(level), C.GoString(file), int(line), int(dmErrnoOrClass), msg) } } + +// DefaultLogger is the default logger used by pkg/devicemapper. It forwards +// all logs that are of higher or equal priority to the given level to the +// corresponding logrus level. +type DefaultLogger struct { + // Level corresponds to the highest libdm level that will be forwarded to + // logrus. In order to change this, register a new DefaultLogger. + Level int +} + +// DMLog is the logging callback containing all of the information from +// devicemapper. The interface is identical to the C libdm counterpart. +func (l DefaultLogger) DMLog(level int, file string, line, dmError int, message string) { + if int(level) <= l.Level { + // Forward the log to the correct logrus level, if allowed by dmLogLevel. + logMsg := fmt.Sprintf("libdevmapper(%d): %s:%d (%d) %s", level, file, line, dmError, message) + switch level { + case LogLevelFatal, LogLevelErr: + logrus.Error(logMsg) + case LogLevelWarn: + logrus.Warn(logMsg) + case LogLevelNotice, LogLevelInfo: + logrus.Info(logMsg) + case LogLevelDebug: + logrus.Debug(logMsg) + default: + // Don't drop any "unknown" levels. + logrus.Info(logMsg) + } + } +} + +// registerLogCallback registers our own logging callback function for libdm +// (which is DevmapperLogCallback). +// +// Because libdm only gives us {0,1} error codes we need to parse the logs +// produced by libdm (to set dmSawBusy and so on). Note that by registering a +// callback using DevmapperLogCallback, libdm will no longer output logs to +// stderr so we have to log everything ourselves. None of this handling is +// optional because we depend on log callbacks to parse the logs, and if we +// don't forward the log information we'll be in a lot of trouble when +// debugging things. +func registerLogCallback() { + LogWithErrnoInit() +} + +func init() { + // Use the default logger by default. We only allow LogLevelFatal by + // default, because internally we mask a lot of libdm errors by retrying + // and similar tricks. Also, libdm is very chatty and we don't want to + // worry users for no reason. + dmLogger = DefaultLogger{ + Level: LogLevelFatal, + } + + // Register as early as possible so we don't miss anything. + registerLogCallback() +} diff --git a/components/engine/pkg/devicemapper/devmapper_wrapper.go b/components/engine/pkg/devicemapper/devmapper_wrapper.go index 4f270fba0b..0fb70fe5b3 100644 --- a/components/engine/pkg/devicemapper/devmapper_wrapper.go +++ b/components/engine/pkg/devicemapper/devmapper_wrapper.go @@ -4,6 +4,7 @@ package devicemapper /* #cgo LDFLAGS: -L. -ldevmapper +#define _GNU_SOURCE #include #include // FIXME: present only for BLKGETSIZE64, maybe we can remove it? @@ -12,19 +13,20 @@ extern void DevmapperLogCallback(int level, char *file, int line, int dm_errno_o static void log_cb(int level, const char *file, int line, int dm_errno_or_class, const char *f, ...) { - char buffer[256]; - va_list ap; + char *buffer = NULL; + va_list ap; - va_start(ap, f); - vsnprintf(buffer, 256, f, ap); - va_end(ap); + va_start(ap, f); + vasprintf(&buffer, f, ap); + va_end(ap); - DevmapperLogCallback(level, (char *)file, line, dm_errno_or_class, buffer); + DevmapperLogCallback(level, (char *)file, line, dm_errno_or_class, buffer); + free(buffer); } static void log_with_errno_init() { - dm_log_with_errno_init(log_cb); + dm_log_with_errno_init(log_cb); } */ import "C" @@ -56,7 +58,6 @@ const ( var ( DmGetLibraryVersion = dmGetLibraryVersionFct DmGetNextTarget = dmGetNextTargetFct - DmLogInitVerbose = dmLogInitVerboseFct DmSetDevDir = dmSetDevDirFct DmTaskAddTarget = dmTaskAddTargetFct DmTaskCreate = dmTaskCreateFct @@ -226,10 +227,6 @@ func dmCookieSupportedFct() int { return int(C.dm_cookie_supported()) } -func dmLogInitVerboseFct(level int) { - C.dm_log_init_verbose(C.int(level)) -} - func logWithErrnoInitFct() { C.log_with_errno_init() }