util-linux/sys-utils test dmesg support for additional timestamp formats #2
Conversation
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
… timestamp This commit adds tests for new functionality in dmesg to support multiple timestamp formats. The user can specify multiple timestamp formats with --time-format option and dmesg prints all the logs with desired timestamp formats in the sequence of user-provided formats. This test verifies that output contains multiple formats in the sequence of input and it also tests for the special case where the user specifies delta format along with either ctime or raw. Signed-off-by: Rishabh Thukral <rthukral@arista.com>
|
Looks good in general, thanks! |
Signed-off-by: Rishabh Thukral <rthukral@arista.com>
|
I've divided the test into subtests. |
karelzak
pushed a commit
that referenced
this pull request
Jan 2, 2024
util-linux/sys-utils dmesg add PRINTK_CALLER support Submission to Project: util-linux Open Incident: util-linux#2609 at github.com/util-linux/issues/2609 Component: util-linux/sys-utils File: dmesg.c Code level patch applied against: 2.39.3 - latest code pulled from git.github.com:util-linux/util-linux.git Revision: #1 on 2023/12/08 per Review from Karel Zak Revision: #2 on 2023/12/12 Adjust line offsets for master update and Add caller_id_size init to dmesg -K Revision: #3 on 2023/12/12 Use of sizeof for cidbuf and limit search for caller_id to dmesg prefix to msg text Revision: util-linux#4 on 2023/12/15 Ensure SYSLOG and kmsg inputs have caller_id_size set appropriately Revision: util-linux#5 on 2023/12/24 Make caller_id width consistent with makedumpfile Revision: util-linux#6 on 2023/12/30 Use updated test naming convention Include expected results for new tests Add support to standard dmesg command for the optional Linux Kernel debug CONFIG option PRINTK_CALLER which adds an optional dmesg field that contains the Thread Id or CPU Id that is issuing the printk to add the message to the kernel ring buffer. This makes debugging simpler as dmesg entries for a specific thread or CPU can be recognized. The dmesg -S using the old syslog interface supports printing the PRINTK_CALLER field but currently standard dmesg does not support printing the field if present. There are utilities that use dmesg and so it would be optimal if dmesg supported PRINTK_CALLER as well. The additional field provided by PRINTK_CALLER is only present if it was configured for the Linux kernel where the dmesg command is run. It is a debug option and not configured by default so the dmesg output will only change for those kernels where the option was configured when the kernel was built. For users who went to the trouble to configure PRINTK_CALLER and have the extra field available for debugging, having dmesg print the field is very helpful. Size of the PRINTK_CALLER field is determined by the maximum number tasks that can be run on the system which is limited by the value of /proc/sys/kernel/pid_max as pid values are from 0 to value - 1. This value determines the number of id digits needed by the caller id. The PRINTK_CALLER field is printed as T<id> for a Task Id or C<id> for a CPU Id for a printk in CPU context. The values are left space padded and enclosed in parentheses such as: [ T123] or [ C16] For consistency with dmesg -S which supports the PRINTK_CALLER field the field is printed followed by a space. For JSON format output the PRINTK_CALLER field is identified as caller as that is consistent with it's naming in /dev/kmsg. No space padding is used to reduce space consumed by the JSON output. So the output from the command on a system with PRINTK_CALLER field enabled in the Linux .config file the dmesg output appears as: > dmesg ... [ 520.897104] [ T3919] usb 3-3: Product: USB 2.0 Hub and > dmesg -x ... kern :info : [ 520.897104] [ T3919] usb 3-3: Product: USB 2.0 Hub and > dmesg -J ... },{ "pri": 6, "time": 520.897104, "caller": "T3919", "msg": "usb 3-3: Product: USB 2.0 Hub" },{ and > dmesg -J -x ... },{ "fac": "kern", "pri": "info", "time": 520.897104, "caller": "T3919", "msg": "usb 3-3: Product: USB 2.0 Hub" },{ > For comparison: > dmesg -S ... [ 520.897104] [ T3919] usb 3-3: Product: USB 2.0 Hub and > dmesg -S -x ... kern :info : [ 520.897104] [ T3919] usb 3-3: Product: USB 2.0 Hub Note: When dmesg uses the old syslog interface the reserved space for the PRINTK_CALLER field is capped at 5 digits because 32-bit kernels are capped at 32768 as the max number of PIDs. However, 64-bit systems are currently capped at 2^22 PIDs (0 - 4194303). The PID cap is set by PID_MAX_LIMIT but the system limit can be less so we use /proc/sys/kernel/pid_max to determine the size needed to hold the maximum PID value size for the current system. Many 64-bit systems support 2^22 PIDs (0 - 4194303) and you see: > dmesg -x ... kern :info : [ 520.899558] [ T3919] hub 3-3:1.0: USB hub found ... kern :info : [ 9830.456898] [ T98982] cgroup: fork rejected by pids ... kern :info : [14301.158878] [ T137336] cgroup: fork rejected by pids ... kern :info : [18980.803190] [T1637865] cgroup: fork rejected by pids ... > dmesg -S -x ... kern :info : [ 520.899558] [ T3919] hub 3-3:1.0: USB hub found ... kern :info : [ 9830.456898] [T98982] cgroup: fork rejected by pids ... kern :info : [14301.158878] [T137336] cgroup: fork rejected by pids ... kern :info : [18980.803190] [T1637865] cgroup: fork rejected by pids ... This is the only difference seen with PRINTK_CALLER configured and printing between the dmesg /dev/kmsg interface and the dmesg -S syslog interface. Tests naming has been revised based on naming convention Thomas used to introduce dmest json tests. The naming of test and input files that reside in tests/ts/dmeg include: <name> are existing dmesg syslog interface tests and input files. cid-<name> are dmesg syslog interface caller_id tests and input files. json-<name> are dmesg kmsg interface tests and input files. cid-json-<name> are dmesg kmsg interface caller_id tests and input files. Resulting expected files match the test names. Signed-off-by: Ivan Delalande <colona@arista.com> Signed-off-by: Edward Chron <echron@arista.com>
karelzak
pushed a commit
that referenced
this pull request
Jan 12, 2024
Submission to Project: util-linux Open Incident: util-linux#2609 at github.com/util-linux/issues/2609 Component: util-linux/sys-utils File: dmesg.c Code level patch applied against: 2.39.3 - latest code pulled from git.github.com:util-linux/util-linux.git Revision: #1 on 2023/12/08 per Review from Karel Zak Revision: #2 on 2023/12/12 Adjust line offsets for master update and Add caller_id_size init to dmesg -K Revision: #3 on 2023/12/12 Use of sizeof for cidbuf and limit search for caller_id to dmesg prefix to msg text Revision: util-linux#4 on 2023/12/15 Ensure SYSLOG and kmsg inputs have caller_id_size set appropriately Revision: util-linux#5 on 2023/12/24 Make caller_id width consistent with makedumpfile Revision: util-linux#6 on 2023/12/30 Use updated test naming convention Revision: util-linux#7 on 2024/01/04 Normalize kmsg caller_id spacing for test platforms by removing caller_id padding in test generated output. Add support to standard dmesg command for the optional Linux Kernel debug CONFIG option PRINTK_CALLER which adds an optional dmesg field that contains the Thread Id or CPU Id that is issuing the printk to add the message to the kernel ring buffer. This makes debugging simpler as dmesg entries for a specific thread or CPU can be recognized. The dmesg -S using the old syslog interface supports printing the PRINTK_CALLER field but currently standard dmesg does not support printing the field if present. There are utilities that use dmesg and so it would be optimal if dmesg supported PRINTK_CALLER as well. The additional field provided by PRINTK_CALLER is only present if it was configured for the Linux kernel where the dmesg command is run. It is a debug option and not configured by default so the dmesg output will only change for those kernels where the option was configured when the kernel was built. For users who went to the trouble to configure PRINTK_CALLER and have the extra field available for debugging, having dmesg print the field is very helpful. Size of the PRINTK_CALLER field is determined by the maximum number tasks that can be run on the system which is limited by the value of /proc/sys/kernel/pid_max as pid values are from 0 to value - 1. This value determines the number of id digits needed by the caller id. The PRINTK_CALLER field is printed as T<id> for a Task Id or C<id> for a CPU Id for a printk in CPU context. The values are left space padded and enclosed in parentheses such as: [ T123] or [ C16] For consistency with dmesg -S which supports the PRINTK_CALLER field the field is printed followed by a space. For JSON format output the PRINTK_CALLER field is identified as caller as that is consistent with it's naming in /dev/kmsg. No space padding is used to reduce space consumed by the JSON output. So the output from the command on a system with PRINTK_CALLER field enabled in the Linux .config file the dmesg output appears as: > dmesg ... [ 520.897104] [ T3919] usb 3-3: Product: USB 2.0 Hub and > dmesg -x ... kern :info : [ 520.897104] [ T3919] usb 3-3: Product: USB 2.0 Hub and > dmesg -J ... },{ "pri": 6, "time": 520.897104, "caller": "T3919", "msg": "usb 3-3: Product: USB 2.0 Hub" },{ and > dmesg -J -x ... },{ "fac": "kern", "pri": "info", "time": 520.897104, "caller": "T3919", "msg": "usb 3-3: Product: USB 2.0 Hub" },{ > For comparison: > dmesg -S ... [ 520.897104] [ T3919] usb 3-3: Product: USB 2.0 Hub and > dmesg -S -x ... kern :info : [ 520.897104] [ T3919] usb 3-3: Product: USB 2.0 Hub Note: When dmesg uses the old syslog interface the reserved space for the PRINTK_CALLER field is capped at 5 digits because 32-bit kernels are capped at 32768 as the max number of PIDs. However, 64-bit systems are currently capped at 2^22 PIDs (0 - 4194303). The PID cap is set by PID_MAX_LIMIT but the system limit can be less so we use /proc/sys/kernel/pid_max to determine the size needed to hold the maximum PID value size for the current system. Many 64-bit systems support 2^22 PIDs (0 - 4194303) and you see: > dmesg -x ... kern :info : [ 520.899558] [ T3919] hub 3-3:1.0: USB hub found ... kern :info : [ 9830.456898] [ T98982] cgroup: fork rejected by pids ... kern :info : [14301.158878] [ T137336] cgroup: fork rejected by pids ... kern :info : [18980.803190] [T1637865] cgroup: fork rejected by pids ... > dmesg -S -x ... kern :info : [ 520.899558] [ T3919] hub 3-3:1.0: USB hub found ... kern :info : [ 9830.456898] [T98982] cgroup: fork rejected by pids ... kern :info : [14301.158878] [T137336] cgroup: fork rejected by pids ... kern :info : [18980.803190] [T1637865] cgroup: fork rejected by pids ... This is the only difference seen with PRINTK_CALLER configured and printing between the dmesg /dev/kmsg interface and the dmesg -S syslog interface. Tests naming has been revised based on naming convention Thomas used to introduce dmest json tests. The naming of test and input files that reside in tests/ts/dmeg include: <name> are existing dmesg syslog interface tests and input files. cid-<name> are dmesg syslog interface caller_id tests and input files. json-<name> are dmesg kmsg interface tests and input files. cid-json-<name> are dmesg kmsg interface caller_id tests and input files. Resulting expected files match the test names. Signed-off-by: Ivan Delalande <colona@arista.com> Signed-off-by: Edward Chron <echron@arista.com>
karelzak
pushed a commit
that referenced
this pull request
Jan 15, 2024
Submission to Project: util-linux Open Incident: util-linux#2609 at github.com/util-linux/issues/2609 Component: util-linux/sys-utils File: dmesg.c Code level patch applied against: 2.39.3 - latest code pulled from git.github.com:util-linux/util-linux.git Revision: #1 on 2023/12/08 per Review from Karel Zak Revision: #2 on 2023/12/12 Adjust line offsets for master update and Add caller_id_size init to dmesg -K Revision: #3 on 2023/12/12 Use of sizeof for cidbuf and limit search for caller_id to dmesg prefix to msg text Revision: util-linux#4 on 2023/12/15 Ensure SYSLOG and kmsg inputs have caller_id_size set appropriately Revision: util-linux#5 on 2023/12/24 Make caller_id width consistent with makedumpfile Revision: util-linux#6 on 2023/12/30 Use updated test naming convention Revision: util-linux#7 on 2024/01/04 Normalize kmsg caller_id spacing for test platforms by removing caller_id padding in test generated output. Add support to standard dmesg command for the optional Linux Kernel debug CONFIG option PRINTK_CALLER which adds an optional dmesg field that contains the Thread Id or CPU Id that is issuing the printk to add the message to the kernel ring buffer. This makes debugging simpler as dmesg entries for a specific thread or CPU can be recognized. The dmesg -S using the old syslog interface supports printing the PRINTK_CALLER field but currently standard dmesg does not support printing the field if present. There are utilities that use dmesg and so it would be optimal if dmesg supported PRINTK_CALLER as well. The additional field provided by PRINTK_CALLER is only present if it was configured for the Linux kernel where the dmesg command is run. It is a debug option and not configured by default so the dmesg output will only change for those kernels where the option was configured when the kernel was built. For users who went to the trouble to configure PRINTK_CALLER and have the extra field available for debugging, having dmesg print the field is very helpful. Size of the PRINTK_CALLER field is determined by the maximum number tasks that can be run on the system which is limited by the value of /proc/sys/kernel/pid_max as pid values are from 0 to value - 1. This value determines the number of id digits needed by the caller id. The PRINTK_CALLER field is printed as T<id> for a Task Id or C<id> for a CPU Id for a printk in CPU context. The values are left space padded and enclosed in parentheses such as: [ T123] or [ C16] For consistency with dmesg -S which supports the PRINTK_CALLER field the field is printed followed by a space. For JSON format output the PRINTK_CALLER field is identified as caller as that is consistent with it's naming in /dev/kmsg. No space padding is used to reduce space consumed by the JSON output. So the output from the command on a system with PRINTK_CALLER field enabled in the Linux .config file the dmesg output appears as: > dmesg ... [ 520.897104] [ T3919] usb 3-3: Product: USB 2.0 Hub and > dmesg -x ... kern :info : [ 520.897104] [ T3919] usb 3-3: Product: USB 2.0 Hub and > dmesg -J ... },{ "pri": 6, "time": 520.897104, "caller": "T3919", "msg": "usb 3-3: Product: USB 2.0 Hub" },{ and > dmesg -J -x ... },{ "fac": "kern", "pri": "info", "time": 520.897104, "caller": "T3919", "msg": "usb 3-3: Product: USB 2.0 Hub" },{ > For comparison: > dmesg -S ... [ 520.897104] [ T3919] usb 3-3: Product: USB 2.0 Hub and > dmesg -S -x ... kern :info : [ 520.897104] [ T3919] usb 3-3: Product: USB 2.0 Hub Note: When dmesg uses the old syslog interface the reserved space for the PRINTK_CALLER field is capped at 5 digits because 32-bit kernels are capped at 32768 as the max number of PIDs. However, 64-bit systems are currently capped at 2^22 PIDs (0 - 4194303). The PID cap is set by PID_MAX_LIMIT but the system limit can be less so we use /proc/sys/kernel/pid_max to determine the size needed to hold the maximum PID value size for the current system. Many 64-bit systems support 2^22 PIDs (0 - 4194303) and you see: > dmesg -x ... kern :info : [ 520.899558] [ T3919] hub 3-3:1.0: USB hub found ... kern :info : [ 9830.456898] [ T98982] cgroup: fork rejected by pids ... kern :info : [14301.158878] [ T137336] cgroup: fork rejected by pids ... kern :info : [18980.803190] [T1637865] cgroup: fork rejected by pids ... > dmesg -S -x ... kern :info : [ 520.899558] [ T3919] hub 3-3:1.0: USB hub found ... kern :info : [ 9830.456898] [T98982] cgroup: fork rejected by pids ... kern :info : [14301.158878] [T137336] cgroup: fork rejected by pids ... kern :info : [18980.803190] [T1637865] cgroup: fork rejected by pids ... This is the only difference seen with PRINTK_CALLER configured and printing between the dmesg /dev/kmsg interface and the dmesg -S syslog interface. Tests naming has been revised based on naming convention Thomas used to introduce dmest json tests. The naming of test and input files that reside in tests/ts/dmeg include: <name> are existing dmesg syslog interface tests and input files. cid-<name> are dmesg syslog interface caller_id tests and input files. json-<name> are dmesg kmsg interface tests and input files. cid-json-<name> are dmesg kmsg interface caller_id tests and input files. Resulting expected files match the test names. Signed-off-by: Ivan Delalande <colona@arista.com> Signed-off-by: Edward Chron <echron@arista.com>
karelzak
pushed a commit
that referenced
this pull request
Jan 23, 2024
Submission to Project: util-linux Open Incident: util-linux#2609 at github.com/util-linux/issues/2609 Component: util-linux/sys-utils File: dmesg.c Code level patch applied against: 2.39.3 - latest code pulled from git.github.com:util-linux/util-linux.git Revision: #1 on 2023/12/08 per Review from Karel Zak Revision: #2 on 2023/12/12 Adjust line offsets for master update and Add caller_id_size init to dmesg -K Revision: #3 on 2023/12/12 Use of sizeof for cidbuf and limit search for caller_id to dmesg prefix to msg text Revision: util-linux#4 on 2023/12/15 Ensure SYSLOG and kmsg inputs have caller_id_size set appropriately Revision: util-linux#5 on 2023/12/24 Make caller_id width consistent with makedumpfile Revision: util-linux#6 on 2023/12/30 Use updated test naming convention Revision: util-linux#7 on 2024/01/04 Normalize kmsg caller_id spacing for test platforms by removing caller_id padding in test generated output. Add support to standard dmesg command for the optional Linux Kernel debug CONFIG option PRINTK_CALLER which adds an optional dmesg field that contains the Thread Id or CPU Id that is issuing the printk to add the message to the kernel ring buffer. This makes debugging simpler as dmesg entries for a specific thread or CPU can be recognized. The dmesg -S using the old syslog interface supports printing the PRINTK_CALLER field but currently standard dmesg does not support printing the field if present. There are utilities that use dmesg and so it would be optimal if dmesg supported PRINTK_CALLER as well. The additional field provided by PRINTK_CALLER is only present if it was configured for the Linux kernel where the dmesg command is run. It is a debug option and not configured by default so the dmesg output will only change for those kernels where the option was configured when the kernel was built. For users who went to the trouble to configure PRINTK_CALLER and have the extra field available for debugging, having dmesg print the field is very helpful. Size of the PRINTK_CALLER field is determined by the maximum number tasks that can be run on the system which is limited by the value of /proc/sys/kernel/pid_max as pid values are from 0 to value - 1. This value determines the number of id digits needed by the caller id. The PRINTK_CALLER field is printed as T<id> for a Task Id or C<id> for a CPU Id for a printk in CPU context. The values are left space padded and enclosed in parentheses such as: [ T123] or [ C16] For consistency with dmesg -S which supports the PRINTK_CALLER field the field is printed followed by a space. For JSON format output the PRINTK_CALLER field is identified as caller as that is consistent with it's naming in /dev/kmsg. No space padding is used to reduce space consumed by the JSON output. So the output from the command on a system with PRINTK_CALLER field enabled in the Linux .config file the dmesg output appears as: > dmesg ... [ 520.897104] [ T3919] usb 3-3: Product: USB 2.0 Hub and > dmesg -x ... kern :info : [ 520.897104] [ T3919] usb 3-3: Product: USB 2.0 Hub and > dmesg -J ... },{ "pri": 6, "time": 520.897104, "caller": "T3919", "msg": "usb 3-3: Product: USB 2.0 Hub" },{ and > dmesg -J -x ... },{ "fac": "kern", "pri": "info", "time": 520.897104, "caller": "T3919", "msg": "usb 3-3: Product: USB 2.0 Hub" },{ > For comparison: > dmesg -S ... [ 520.897104] [ T3919] usb 3-3: Product: USB 2.0 Hub and > dmesg -S -x ... kern :info : [ 520.897104] [ T3919] usb 3-3: Product: USB 2.0 Hub Note: When dmesg uses the old syslog interface the reserved space for the PRINTK_CALLER field is capped at 5 digits because 32-bit kernels are capped at 32768 as the max number of PIDs. However, 64-bit systems are currently capped at 2^22 PIDs (0 - 4194303). The PID cap is set by PID_MAX_LIMIT but the system limit can be less so we use /proc/sys/kernel/pid_max to determine the size needed to hold the maximum PID value size for the current system. Many 64-bit systems support 2^22 PIDs (0 - 4194303) and you see: > dmesg -x ... kern :info : [ 520.899558] [ T3919] hub 3-3:1.0: USB hub found ... kern :info : [ 9830.456898] [ T98982] cgroup: fork rejected by pids ... kern :info : [14301.158878] [ T137336] cgroup: fork rejected by pids ... kern :info : [18980.803190] [T1637865] cgroup: fork rejected by pids ... > dmesg -S -x ... kern :info : [ 520.899558] [ T3919] hub 3-3:1.0: USB hub found ... kern :info : [ 9830.456898] [T98982] cgroup: fork rejected by pids ... kern :info : [14301.158878] [T137336] cgroup: fork rejected by pids ... kern :info : [18980.803190] [T1637865] cgroup: fork rejected by pids ... This is the only difference seen with PRINTK_CALLER configured and printing between the dmesg /dev/kmsg interface and the dmesg -S syslog interface. Tests naming has been revised based on naming convention Thomas used to introduce dmest json tests. The naming of test and input files that reside in tests/ts/dmeg include: <name> are existing dmesg syslog interface tests and input files. cid-<name> are dmesg syslog interface caller_id tests and input files. json-<name> are dmesg kmsg interface tests and input files. cid-json-<name> are dmesg kmsg interface caller_id tests and input files. Resulting expected files match the test names. Signed-off-by: Ivan Delalande <colona@arista.com> Signed-off-by: Edward Chron <echron@arista.com> Signed-off-by: Karel Zak <kzak@redhat.com>
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
This commit adds tests for new functionality in
dmesgto support multiple timestamp formats. The user can specify multiple timestamp formats with--time-formatoption anddmesgprints all the logs with desired timestamp formats in the sequence of user-provided formats.This test verifies that output contains multiple formats in the sequence of input and it also tests for the special case where the user specifies delta format along with either ctime or raw. There are 4 total cases tested
raw,ctime, andisoiso, anddeltareltime,delta, andctimeraw,ctime, anddelta