[dm-devel] [RFC] New Logging approach for Device Mapper
Chauhan, Vijay
Vijay.Chauhan at lsi.com
Sat Sep 5 19:06:02 UTC 2009
Hi Alasdair and All,
Currently device mapper has DMCRIT, DMERR, DMWARN & DMINFO macros for logging messages. These macros are printk's with printk levels KERN_CRIT, KERN_ERR, KERN_WARNING & KERN_INFO respectively.
---------------------------------------------------
Following are the disadvantages with above approach:
---------------------------------------------------
* To enable these logs we need to set printk levels which may also enable all other printk's (non dm related) resulting in populating syslog.
* We do not have sub categories within each Log type in DM. As a reason enabling specific logging type enables all the logging messages set at their printk level. It may take more time for us in filtering the relevant messages.
-----------------------------
New proposal for dm logging :
-----------------------------
Below is the new logging style I am proposing for device mapper. The format is very similar to scsi logging level.
Thanks Chandra for his initial comments and reviews.
I am replacing existing [DMCRIT, DMERR, DMWARN & DMINFO] macros with [DMLOG] macro which looks as following:
#define DMLOG_BITS 2
# define DMLOG_LEVEL(SHIFT) \
((dm_logging_level >> (SHIFT * DMLOG_BITS)) & ((1 << (DMLOG_BITS)) - 1))
# define DMLOG( SHIFT, LEVEL, f, arg...) \
do { \
if ((DMLOG_LEVEL(SHIFT)) >= (LEVEL)) \
do { \
printk(DM_NAME ": " DM_MSG_PREFIX ": " \
"DEBUG: %s: " f "\n", __FUNCTION__, ## arg); \
} while (0); \
} while (0)
I am adding dm_logging_level (unsigned int ) as module param in dm-mod kernel module. This is used to set dm logging level on-the-fly as
echo "[LEVEL]" >/sys/module/dm_mod/parameters/dm_logging_level
or
at the load time from modprobe config file with following setting:
options dm-mod dm_logging_level=[level]
Each logging type is represented with 2 bits in dm_logging_level. Following are the logging types currently defined :
DMLOG_INIT
DMLOG_ADD_DEV
DMLOG_REMOVE_DEV
DMLOG_IOCTL
DMLOG_IO
DMLOG_UEVENT
DM_LOG_TABLE
DMLOG_FAILOVER //for multipath
DMLOG_PATH_ACTIVATE
DMLOG_PATH_DEACTIVATE
These 2 bits for each logging type are used to represent either of 4 logging levels mentioned below:
/* DM Logging level */
#define DMLOG_CRIT 0 //CRITICAL
#define DMLOG_ERR 1 //ERROR
#define DMLOG_WARN 2 //WARNING
#define DMLOG_INFO 3 //INFORMATIONAL
---------------------------------------
dm_logging_level bitwise representation
---------------------------------------
20 18 16 14 12 10 8 6 4 2 0
..|_|_|_|_|_|_|_|_|_|_|_|_|_|_|_|_|_|_|_|_|
\ \ \ \ \ \ \ \ \ \_DMLOG_INIT
\ \ \ \ \ \ \ \ \_DMLOG_ADD_DEV
\ \ \ \ \ \ \ \_DMLOG_REMOVE_DEV
\ \ \ \ \ \ \_DMLOG_IOCTL
\ \ \ \ \ \_DMLOG_IO
\ \ \ \ \_DMLOG_UEVENT
\ \ \ \_DMLOG_TABLE
\ \ \_DMLOG_FAILOVER
\ \_DMLOG_PATH_ACTIVATE
\_DMLOG_PATH_DEACTIVATE
----------------------------------
How to add logging in DM code:
----------------------------------
Logs can be added in code with DMLOG macro in following format:
DMLOG([DMLOG TYPE], [DMLOG LEVEL], [DEBUG message]);
Ex:
DMLOG(DMLOG_INIT, DMLOG_INFO, "path selector %s registered successfully", pst->name);
-----------------------------------
How to enable DM logging
------------------------------------
1) DM logging can be enabled on-the-fly by setting /sys/module/dm_mod/parameters/dm_logging_level.
For example: To enable DMLOG_INIT logs for all ERROR (i.e DMLOG_ERR level) and DMLOG_ADD_DEV logs at DMLOG_INFO level, we can set as
follows:
4 2 0
|_|_|_|_|
1 1 0 1 -->0x0d or 13
echo 0x0000000d > >/sys/module/dm_mod/parameters/dm_logging_level
or
echo 13 >/sys/module/dm_mod/parameters/dm_logging_level
(PS: If the above approach looks fine then I can come up with more user friendly interface to set logging from
dmsetup utility)
2) At boot time by mentioning it in modprobe.conf:
options dm-mod dm_logging_level=13
--------------------------------------------
Advantage of using new DM LOGGING style:
--------------------------------------------
* Logging level can be enabled with specific logging types. This avoids populating non-relevant logging messages.
* Each logging type can be set with their respective logging level. It will help in filtering and root causing issue with ease.
* ALL critical messages with be logged by default
------------
Limitation
------------
* CONFIG_DM_DEBUG=y should be set in order to enable dm logging
--------------------------------------------------
Following are syslog snippet with debug enabled:
--------------------------------------------------
Sep 5 18:31:54 localhost kernel: device-mapper: ioctl: DEBUG: dm_hash_insert: Successfully inserted 3600a0b80003908f9000057c74a839420 in hash table
Sep 5 18:31:54 localhost kernel: device-mapper: ioctl: DEBUG: ctl_ioctl: IOCTL command 0xc138fd09 called from userspace.
Sep 5 18:31:54 localhost kernel: device-mapper: ioctl: DEBUG: ctl_ioctl: IOCTL command 0xc138fd06 called from userspace.
Sep 5 18:31:54 localhost kernel: device-mapper: core: DEBUG: dm_suspend: Setting DMF_BLOCK_IO_FOR_SUSPEND and DMF_QUEUE_IO_TO_THREAD flags for 253:0
Sep 5 18:31:54 localhost kernel: device-mapper: core: DEBUG: dm_suspend: Setting DMF_SUSPENDED flag for 253:0
Sep 5 18:31:54 localhost kernel: device-mapper: core: DEBUG: dm_resume: Unsetting DMF_SUSPENDED flag for 253:0
Sep 5 18:31:54 localhost kernel: device-mapper: ioctl: DEBUG: ctl_ioctl: IOCTL command 0xc138fd0e called from userspace.
Sep 5 18:31:54 localhost multipathd: 3600a0b80003908f9000057c74a839420: load table [0 204800 multipath 2 pg_init_retries 50 0 1 1 round-robin 0 1 1 8:32 100]
Sep 5 18:32:01 localhost kernel: device-mapper: ioctl: DEBUG: ctl_ioctl: IOCTL command 0xc138fd02 called from userspace.
Sep 5 18:32:02 localhost kernel: device-mapper: ioctl: DEBUG: ctl_ioctl: IOCTL command 0xc138fd0c called from userspace.
Sep 5 18:32:02 localhost last message repeated 2 times
Sep 5 18:32:02 localhost kernel: device-mapper: ioctl: DEBUG: ctl_ioctl: IOCTL command 0xc138fd07 called from userspace.
Sep 5 18:32:02 localhost last message repeated 2 times
Sep 5 18:32:02 localhost kernel: device-mapper: ioctl: DEBUG: ctl_ioctl: IOCTL command 0xc138fd03 called from userspace.
Sep 5 18:32:02 localhost kernel: device-mapper: ioctl: DEBUG: dev_create: Creating dm device for 3600a0b80003908f9000057c64a83941a
Sep 5 18:32:02 localhost kernel: device-mapper: ioctl: DEBUG: dm_hash_insert: inserting 3600a0b80003908f9000057c64a83941a in hash table
Sep 5 18:32:02 localhost kernel: device-mapper: ioctl: DEBUG: dm_hash_insert: Successfully inserted 3600a0b80003908f9000057c64a83941a in hash table
Sep 5 18:32:02 localhost kernel: device-mapper: ioctl: DEBUG: ctl_ioctl: IOCTL command 0xc138fd00 called from userspace.
Sep 5 18:32:02 localhost kernel: device-mapper: ioctl: DEBUG: ctl_ioctl: IOCTL command 0xc138fd07 called from userspace.
Sep 5 18:32:02 localhost kernel: device-mapper: ioctl: DEBUG: ctl_ioctl: IOCTL command 0xc138fd09 called from userspace.
Sep 5 18:32:02 localhost kernel: device-mapper: ioctl: DEBUG: ctl_ioctl: IOCTL command 0xc138fd06 called from userspace.
Sep 5 18:32:02 localhost kernel: device-mapper: core: DEBUG: dm_suspend: Setting DMF_BLOCK_IO_FOR_SUSPEND and DMF_QUEUE_IO_TO_THREAD flags for 253:1
Sep 5 18:32:02 localhost kernel: device-mapper: core: DEBUG: dm_suspend: Setting DMF_SUSPENDED flag for 253:1
Sep 5 18:32:02 localhost kernel: device-mapper: core: DEBUG: dm_resume: Unsetting DMF_SUSPENDED flag for 253:1
Sep 5 18:32:02 localhost kernel: device-mapper: ioctl: DEBUG: ctl_ioctl: IOCTL command 0xc138fd0e called from userspace.
Sep 5 18:32:02 localhost kernel: device-mapper: ioctl: DEBUG: ctl_ioctl: IOCTL command 0xc138fd02 called from userspace.
Sep 5 18:32:02 localhost kernel: device-mapper: ioctl: DEBUG: ctl_ioctl: IOCTL command 0xc138fd0c called from userspace.
Sep 5 18:32:03 localhost multipathd: 3600a0b80003908f9000057c64a83941a: load table [0 204800 multipath 2 pg_init_retries 50 0 1 1 round-robin 0 1 1 8:16 100]
Sep 5 18:32:07 localhost kernel: device-mapper: ioctl: DEBUG: ctl_ioctl: IOCTL command 0xc138fd0c called from userspace.
Sep 5 18:32:07 localhost multipathd: 3600a0b80003908f9000057c84a839426: load table [0 204800 multipath 2 pg_init_retries 50 0 1 1 round-robin 0 1 1 8:48 100]
Sep 5 18:32:07 localhost kernel: device-mapper: ioctl: DEBUG: ctl_ioctl: IOCTL command 0xc138fd0c called from userspace.
Sep 5 18:32:07 localhost multipathd: 3600a0b80003908f9000057ca4a839432: load table [0 204800 multipath 2 pg_init_retries 50 0 1 1 round-robin 0 1 1 8:80 100]
Thanks,
Vijay
More information about the dm-devel
mailing list