Add support to standard dmesg command for the optional Linux Kernel debug CONFIG option PRINTK_CALLER field #2609
Comments
|
Adding the util-linux//sys-utils patch here as a gzip format file (it wouldn't let me add it as a *.patch file it said that file type is not supported even though it is listed as supported. util-linux-sys-utils-dmesg-add-PRINTK_CALLER-support-issue_2609.patch.gz |
|
The dmesg PRINTK_CALLER field is enclosed by parentheses and begins with a C for CPU id or T for Thread is and is followed by the appropriate id number for the CPU or Thread that issued the printk call. This is the same format used by dmesg -S. The dmesg -S format allows 6 characters between the parentheses and the C/Tid# are left space padded. The reason 6 characters are used is to accomodate the C/T identifier plus 5 digits. This is because 32 bit systems had a maximum number of PIDs of 32,768 so 5 digits fit the id. However, newer 64-bit systems currently support up to 2^22 PIDs maximum and the /proc/sys/kernel/pid_max field The patch was tested with various dmesg options, including the -J JSON option run against Linux 6.6.1 on two two systems, one with the PRINTK_CALLER Linux config option enabled and on another Linux 6.6.1 system where PRINTK_CALLER was not configured. The dmesg command produces output like this on the system with PRINTK_CALLER configured: dmesg or with dmesg -x For JSON output it produces dmesg -J -x: Just keep in mind that dmesg and dmesg -S output may differ just in the padding of the PRINTK_CALLER field, shown here dmesg -x versus dmesg -S -x that accomodates 6 characters (C|T)##### since it assumes a Max number of PIDs of 32768: We can supply additional testing output if that would be helpful. |
|
Could you submit the patch as a pullrequest? Or as patch to the mailing list? Also a testcase would be great :-) |
|
Sure, will add results of test cases that I ran here with the patch to util-linux dmesg both on kernels that have PRINTK_CALLER enabled and systems that have the dmesg patch applied but do not have PRINTK_CALLER enabled in the kernel config, to verifuy it works with either case. Will add those shortly. |
|
I sent the patch and will post our testing results here. |
|
Thanks! |
|
Sure, will post tests/ts/dmesg results, Thank you. |
|
So I ran the tests/ts/dmesg/ tests as recommended. However, I ran them first against standard Fedora 39 dmesg which is 2.39.2 so almost the latest code. What I found is that when I run against a default config kernel: Linux-6.6.3 the tests pass. However, without modifying dmesg (i.e. my patch is not installed, running vanilla 2.39.2) but running against a Linux-6.6.3 kernel with the PRINTK_CALLER config option enabled two of your 7 tests fail: limit and indentation. The reason for this is because your testing against the SYSLOG interface (dmesg -S) and PRINTK_CALLER introduces an optional field, that's the whole point of that configuration option. The syslog dmesg interface supports optional fields just like my change does for standard dmesg. So the additional field causes these two subtests to fail. Of course the same two subtests fail in the same way with my dmesg patch, but the patch is not the cause of the failure, just configuring the PRINTK_CALLER kernel option causes the failure. So I have two questions for you:
Adding PRINTK_CALLER support for the standard dmesg interface is worth the hassle of fixing the tests. Let me know the answer to the questions so will I know if I should proceeed. Thank you, Edward |
|
util-linux dmesg testingMy testing was on Fedora 39 with an unmodified Linux Kernel so the PRINTK_CALLER option is not configured. Here is the environment where I ran my tests, standard Fedora 39 workstation: [echron@zuma util-linux]$ uname -a [echron@zuma util-linux]$ cat /etc/fedora-release. For the util-linux code I used I did: $ git clone https://github.com/util-linux/util-linux.git yesterday morning: Dec 6 10:02 PST So the test code I am using is up to date. First I ran the test without properly setting up the dmesg testing link. An improvement would be to fix this so that the tests fail or aren't run at all because the tests in fact were not run so they should not be reported as passing. I will include a fix for this in my changes unless you have objections. [echron@zuma util-linux]$ tests/run.sh dmesg -------------------- util-linux regression tests -------------------- All 7 tests PASSEDNext I set up the required test link so the test is correctly run: [echron@zuma util-linux]$ ls -l test_dmesg [echron@zuma util-linux]$ ls -l /usr/bin/dmesg [echron@zuma util-linux]$ /usr/bin/dmesg -V Now run the tests with the environment correctly setup: [echron@zuma util-linux]$ tests/run.sh dmesg -------------------- util-linux regression tests -------------------- 2 tests of 7 FAILED So this appears to be failing with an unmodified dmesg 2.39.2 from Fedora 39. Am I running the test incorrectly? As mentioned these tests are running dmesg -F which is the old syslog interface. So these tests won't test my change even if they worked correctly. The question is what do you want for tests that properly test my enhancement? Do you want me to come up with replacement or equivalent tests to indentation and limit but that work with the dmesg standard interface? Would that be sufficient? Any new tests I will include as a second patch along with my current patch for this issue. Changes to tests to verify that an enhancement works correctly should be included here, but we usually put test changes in separate patches. I can open a separate issue for the two tests failing that use the syslog interface if you agree that tests are in fact broken. I would like to know the existing tests work correctly first before proceeding. So let me know if you agree there is an issue with the existing tests. Thank you. |
All tests are ran during CI for a variety of platforms and any breakage has a fairly high priority to get fixed.
All tests should be using input from a file that is part of the testsuite.
Some tests that simulate the syslog input from a file.
Personally I prefer to keep them together, at least in the same series. |
|
OK, Thanks Thomas. I will follow you recommendations and also incorporate the feedback issues Karel provided in his code review of the patch. Since we don't have tests for syslog with PRINTK-CALLER, I put those together and will open a separate indcident for those, since this is about dmesg standard interface (dev/kmsg) supporting PRINTK_CALLER. For developing tests for PRINTK _CALLER dmesg -S (suslong interface) I picked up fixes you posted to your branch: t8ch/dmesg/tests I needed some of your fixes to get the tests for syslog PRINT_CALLER versions to pass. Thanks again to Thomas and Karel for their guidance and code reviews to improve this submission. |
|
Sent patch to the mailing list with revisions for Karel's feedback sent on Friday 12/08. |
|
Picking up Thomas latest dmesg -K code so I can input simulated /dev/kmsg tests, very timely, Thank you Thomas! |
Surely pure coincidence :-) |
|
Thankful for coincidences. :-) |
|
Sent the patch revised to work with all the kmsg interface PRINTK_CALLER tests plus the json PRINT_CALLER test for the SYSLOG interface. The revision 2 patch includes these modifed and added files: M include/pathnames.h A tests/expected/dmesg/colors-kmsg-printk-caller A tests/ts/dmesg/colors-kmsg-printk-caller Sorry that I sent it up as initially tagged it as Issue #2906 I meant #2609 but I caught my mistake and resent. |
|
If install this patch and run the tests you get: [echron@zuma util-linux]$ tests/run.sh dmesg -------------------- util-linux regression tests -------------------- All 19 tests PASSED |
|
Review comments by Thomas:
Could this be made more robust by looking for the field in the expected location and not the whole message? OK: but according to the Linux Kernel documentation there may be multiple optional fields in dmesg so I can restrict the check to before the semi-colon. That way if additional optional fields are added we won't have to worry about order as I am not sure how they would order them. Doesn't matter since the field is tagged with caller= so we just need to search for that, but I can restrict that to the prefix before the message text so I'll make that change. Thanks for catching that.
Done, will be included in Revision 3 which I will submit shortly. |
|
Sent util-linux-sys-utils-dmesg-2609-rev3.patch as a pullrequest |
|
@egchron, would it be better to create a pull request on GitHub? |
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 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. Signed-off-by: Ivan Delalande <colona@arista.com> Signed-off-by: Edward Chron <echron@arista.com>
|
Yes, I sent the patch as revision3 as a pull request on Github and it is listed in the mailing list: https://marc.info/?l=util-linux-ng&m=170244925032107&w=2
|
|
So hopefully, I've addressed all the Review Comments from Zak and Thomas so far, and the tests submitted will help with the Review and testing. I also submitted SYSLOG tests for PRINTK_CALLER with Issue #2637 since it was discussed that we didn't have any and my understanding is that we needed some tests for a base comparison between the PRINTK_CALLER with SYSLOG interface (already supported but we didn't have any tests) and with the kmsg interface. The code here in this patch (updated by revision 3) includes the code needed for PRINTK_CALLER to work correctlty with the kmsg interface for testing: dmesg -K and the SYSLOG interface dmesg -F This patch also includes the json test for the SYSLOG PRINTK_CALLER as Thomas added that test after (while) I created the SYSLOG PRINTK_CALLER tests so I didn't have it to test with when I wrote the tests in Issue #2637. So for complete testing picking up the tests from Issue #2637 and the Revision 3 patch for this Issue #2609 provides the latest revision of the dmesg code and hopefully all the tests that would be needed to test and validate the code. Thank you |
|
#2647 is the patch from the mailing list (v3) |
|
FYI, Posted as a pull request on GitHub, mailing list: update to patch for 2609, revision 4 https://marc.info/?l=util-linux-ng&m=170290902409140&w=2 Message-ID: 20231218141511.31404-1-echron () arista ! com Submission to Project: util-linux ... |
|
I sent v4 and I am sending v5 of the patch revisions so that the caller_id field matches what is present with dmesg -S and what we want for the dmesg kmsg interface and to have it match what is going for makedumpfile since I've submitted a patch to add caller_id to makedumpfile and crash as well. They would like the field width for caller_id field width to match what the dmesg kmsg interface uses. That should be 1 character for T or C (thread or CPU Identifier) and up to 7 characters for thread id with appropriate left padding for unused to characters all within square brackets. Revision 5 patch: util-linux-sys-utils-dmesg-2609-rev5.patch.gz I'll also post this. |
|
Revision 6 - renamed tests to match test naming convention that Thomas introduced: Subject: [PATCH] util-linux/sys-utils dmesg add PRINTK_CALLER support Submission to Project: util-linux Add support to standard dmesg command for the optional Linux Kernel The dmesg -S using the old syslog interface supports printing the ... Tests naming has been revised based on naming convention Thomas used to Resulting expected files match the test names. [echron@catalina util-linux]$ tests/run.sh dmesg -------------------- util-linux regression tests -------------------- All 18 tests PASSEDRevision 6 patch: util-linux-sys-utils-dmesg-2609-rev6.patch.gz I'll also post it to the mailing list. |
|
Recommend you pick up the 4 patches that are a series with Issue: #2666 that has all code for Issues: 2609, 2637 and 2663 which the updated patch for 2609 and the tests and input files dmesg kmsg PRINTK_CALLER id but also the tests and input files dmesg syslog PRINTK_CALLER id and tests and input files for dmesg kmsg generic interface. |
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>
Submission to Project: util-linux Open Incident: util-linux#2637 at github.com/util-linux/issues/2637 Component: util-linux/sys-utils Files: tests/ts/dmesg syslog interface caller-id files, tests and related expected files Testing on Fedora 39 with Linux-6.6.6 Kernel and CONFIG_PRINTK_CALLER config option set. Patch tested and generated with the latest util-linux code pulled. Retro-fitted to merge on top of the patch for Issue: util-linux#2609 For Issue util-linux#2609 Thomas and Zak pointed out the we need tests to verify that the dmesg command works correctly and to allow us to compare the results from PRINTK_CALLER id field tests provided by util-linux#2609 with the standard (syslog interface) dmesg tests. Currently, dmesg only has standard syslog interface tests even though dmesg -S the syslog interface supports the caller_id field. There are no syslog caller-id tests. We would like syslog caller-id tests both to validate that the dmesg code works correctly with the caller-id field being present and also to compare against the addition of dmesg kmsg caller_id support added by Issue util-linux#2609. These tests are for the dmesg syslog interface with caller-id follow the existing test structure for dmesg tests. The existing dmesg -F interface is used to input our test files. Until Thomas added a dmesg kmsg interface for json format testing there were no dmesg tests except the tests for the generic dmesg syslog tests. So we're naming the syslog caller-id tests to follow the test naming convention that Thomas introduced. For caller_id tests we prefix the test name with cid- abbreviating the caller_id name to keep the names short. There is no unqiue indentifier for syslog tests, so syslog tests are currently: colors, console-levels, decode, delta, facilities, indentation, limit, json The cid versions of these test files are just prefixed with cid- The patch for Issue: util-linux#2609 has the files: cid-input and cid-json and the expected file for cide-json Additional new dmesg tests are found with Issue util-linux#2663 which add standard dmesg kmsg interface tests providing equivalent tests to the existing dmesg syslog interface tests. Also, Issue util-linux#2609 introduces dmesg kmsg interface caller-id tests equivalent to the dmesg syslog interface with caller-id tests introduced here along with the necessary dmesg kmsg interface caller-id support needed to accomodate the PRINTK_CALLER id field. Just for reference, on a Linux system with the CONFIG_PRINTK_CALLER configuration option set the output from dmesg -S looks like: [ 520.899558] [ T3919] hub 3-3:1.0: USB hub found on a system where the PRINTK_CALLER configuration option is not set the output looks like: [ 520.899558] hub 3-3:1.0: USB hub found the additional field specifies either a Thread Id or CPU id depending on the context of the task or thread at the time the printk that added the message to the kernel ring buffer was executed. Signed-off-by: Ivan Delalande <colona@arista.com> Signed-off-by: Edward Chron <echron@arista.com>
Submission to Project: util-linux Open Incident: util-linux#2663 at github.com/util-linux/issues/2663 Component: util-linux/sys-utils Files: tests/ts/dmesg kmsg interface files and related expected files Testing on Fedora 39 with Linux-6.6.6 Kernel and CONFIG_PRINTK_CALLER config option set. Patch tested and generated with the latest util-linux code pulled. Revision: no caller optional fields in any of the kmsg-input entries Revision: retrofitted to apply on top of Issue: util-linux#2609 and Issue util-linux#2637 This is patch 1 of 2 (first in the series) Second patch needed to hold second binary file (git binary files issue) For issue util-linux#2609 Thomas and Zak pointed out the we need tests to verify that the dmesg command works correctly and to allow us to compare the results from PRINTK_CALLER id field tests provided by util-linux#2609 with the standard (syslog interface) dmesg tests. Except for a kmsg json test that Thomas added recently we don't have basic dmesg tests for the kmsg interface to compare results against. We added tests for the dmesg SYSLOG PRINTK_CALLER id interface so we can compare against those tests. Those tests were submitted with Issue util-linux#2637. Those tests were created before Thomas added the new dmesg kmsg test and I will rename those tests to match the naming scheme that Thomas is using for tests that are specific to syslog interface and specific to kmsg interface. Issue util-linux#2609 introduces dmesg kmsg interface support for the PRINTK_CALLER id field and provides tests to compare against the SYSLOG interface tests added by util-linux#2637. Those tests also need to renamed to be consistent Thomas's test naming scheme. Here we've created tests for the dmesg kmsg interface following the existing test structure for dmesg tests. With the addition of this set of tests, we have tests for SYSLOG and SYSLOG PRINTK_CALLER id field to compare against the kmsg and kmsg PRINTK_CALLER id field tests. Currently the only kmsg interface specific test that exists is the kmsg-file test that Thomas added to test the dmesg kmsg interface for json support. Thomas also added code for the -K file interface to process dmesg ksmg interface files for testing so we utilize that code here and add to it. The kmsg-input file is expanded to provide statements and fields to completely test the kmsg interface with tests that are equivalent to the SYSLOG interface dmesg tests. Additionally a ksmg-newlines file is added which provides kmsg format for testing with indentation. The output of the existing kmsg-file test is adjusted to match the expanded kmsg-input file. All tests follow the standard util-linux tests format used by dmesg for unit tests. Signed-off-by: Ivan Delalande <colona@arista.com> Signed-off-by: Edward Chron <echron@arista.com>
Submission to Project: util-linux Open Incident: util-linux#2663 at github.com/util-linux/issues/2663 Component: util-linux/sys-utils Files: tests/ts/dmesg kmsg interface files and related expected files Testing on Fedora 39 with Linux-6.6.6 Kernel and CONFIG_PRINTK_CALLER config option set. Patch tested and generated with the latest util-linux code pulled. Revision: no caller optional fields in any of the kmsg-input entries Revision: retrofitted to apply on top of Issue: util-linux#2609 and Issue util-linux#2637 This is patch 2 of 2 (second in the series) A second patch needed to hold 2nd binary file (git binary files issue) This patch is needed because git format does not produce correct output if two binary files are included in the same patch. So adding the second binary file in a second patch to resolve the issue. Signed-off-by: Ivan Delalande <colona@arista.com> Signed-off-by: Edward Chron <echron@arista.com>
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>
Submission to Project: util-linux Open Incident: util-linux#2637 at github.com/util-linux/issues/2637 Component: util-linux/sys-utils Files: tests/ts/dmesg syslog interface caller-id files, tests and related expected files Testing on Fedora 39 with Linux-6.6.6 Kernel and CONFIG_PRINTK_CALLER config option set. Patch tested and generated with the latest util-linux code pulled. Retro-fitted to merge on top of the patch for Issue: util-linux#2609 For Issue util-linux#2609 Thomas and Zak pointed out the we need tests to verify that the dmesg command works correctly and to allow us to compare the results from PRINTK_CALLER id field tests provided by util-linux#2609 with the standard (syslog interface) dmesg tests. Currently, dmesg only has standard syslog interface tests even though dmesg -S the syslog interface supports the caller_id field. There are no syslog caller-id tests. We would like syslog caller-id tests both to validate that the dmesg code works correctly with the caller-id field being present and also to compare against the addition of dmesg kmsg caller_id support added by Issue util-linux#2609. These tests are for the dmesg syslog interface with caller-id follow the existing test structure for dmesg tests. The existing dmesg -F interface is used to input our test files. Until Thomas added a dmesg kmsg interface for json format testing there were no dmesg tests except the tests for the generic dmesg syslog tests. So we're naming the syslog caller-id tests to follow the test naming convention that Thomas introduced. For caller_id tests we prefix the test name with cid- abbreviating the caller_id name to keep the names short. There is no unqiue indentifier for syslog tests, so syslog tests are currently: colors, console-levels, decode, delta, facilities, indentation, limit, json The cid versions of these test files are just prefixed with cid- The patch for Issue: util-linux#2609 has the files: cid-input and cid-json and the expected file for cide-json Additional new dmesg tests are found with Issue util-linux#2663 which add standard dmesg kmsg interface tests providing equivalent tests to the existing dmesg syslog interface tests. Also, Issue util-linux#2609 introduces dmesg kmsg interface caller-id tests equivalent to the dmesg syslog interface with caller-id tests introduced here along with the necessary dmesg kmsg interface caller-id support needed to accomodate the PRINTK_CALLER id field. Just for reference, on a Linux system with the CONFIG_PRINTK_CALLER configuration option set the output from dmesg -S looks like: [ 520.899558] [ T3919] hub 3-3:1.0: USB hub found on a system where the PRINTK_CALLER configuration option is not set the output looks like: [ 520.899558] hub 3-3:1.0: USB hub found the additional field specifies either a Thread Id or CPU id depending on the context of the task or thread at the time the printk that added the message to the kernel ring buffer was executed. Signed-off-by: Ivan Delalande <colona@arista.com> Signed-off-by: Edward Chron <echron@arista.com>
Submission to Project: util-linux Open Incident: util-linux#2663 at github.com/util-linux/issues/2663 Component: util-linux/sys-utils Files: tests/ts/dmesg kmsg interface files and related expected files Testing on Fedora 39 with Linux-6.6.6 Kernel and CONFIG_PRINTK_CALLER config option set. Patch tested and generated with the latest util-linux code pulled. Revision: no caller optional fields in any of the kmsg-input entries Revision: retrofitted to apply on top of Issue: util-linux#2609 and Issue util-linux#2637 This is patch 1 of 2 (first in the series) Second patch needed to hold second binary file (git binary files issue) For issue util-linux#2609 Thomas and Zak pointed out the we need tests to verify that the dmesg command works correctly and to allow us to compare the results from PRINTK_CALLER id field tests provided by util-linux#2609 with the standard (syslog interface) dmesg tests. Except for a kmsg json test that Thomas added recently we don't have basic dmesg tests for the kmsg interface to compare results against. We added tests for the dmesg SYSLOG PRINTK_CALLER id interface so we can compare against those tests. Those tests were submitted with Issue util-linux#2637. Those tests were created before Thomas added the new dmesg kmsg test and I will rename those tests to match the naming scheme that Thomas is using for tests that are specific to syslog interface and specific to kmsg interface. Issue util-linux#2609 introduces dmesg kmsg interface support for the PRINTK_CALLER id field and provides tests to compare against the SYSLOG interface tests added by util-linux#2637. Those tests also need to renamed to be consistent Thomas's test naming scheme. Here we've created tests for the dmesg kmsg interface following the existing test structure for dmesg tests. With the addition of this set of tests, we have tests for SYSLOG and SYSLOG PRINTK_CALLER id field to compare against the kmsg and kmsg PRINTK_CALLER id field tests. Currently the only kmsg interface specific test that exists is the kmsg-file test that Thomas added to test the dmesg kmsg interface for json support. Thomas also added code for the -K file interface to process dmesg ksmg interface files for testing so we utilize that code here and add to it. The kmsg-input file is expanded to provide statements and fields to completely test the kmsg interface with tests that are equivalent to the SYSLOG interface dmesg tests. Additionally a ksmg-newlines file is added which provides kmsg format for testing with indentation. The output of the existing kmsg-file test is adjusted to match the expanded kmsg-input file. All tests follow the standard util-linux tests format used by dmesg for unit tests. Signed-off-by: Ivan Delalande <colona@arista.com> Signed-off-by: Edward Chron <echron@arista.com>
Submission to Project: util-linux Open Incident: util-linux#2663 at github.com/util-linux/issues/2663 Component: util-linux/sys-utils Files: tests/ts/dmesg kmsg interface files and related expected files Testing on Fedora 39 with Linux-6.6.6 Kernel and CONFIG_PRINTK_CALLER config option set. Patch tested and generated with the latest util-linux code pulled. Revision: no caller optional fields in any of the kmsg-input entries Revision: retrofitted to apply on top of Issue: util-linux#2609 and Issue util-linux#2637 This is patch 2 of 2 (second in the series) A second patch needed to hold 2nd binary file (git binary files issue) This patch is needed because git format does not produce correct output if two binary files are included in the same patch. So adding the second binary file in a second patch to resolve the issue. Signed-off-by: Ivan Delalande <colona@arista.com> Signed-off-by: Edward Chron <echron@arista.com>
|
I know everyone is busy coming back from the holidays but if you can let us know if we need to change, add or remove tests from this list we can make whatever changes are recommended. The base code that adds PRINTK_CALLER id support for the /dev/kmsg interface is working and we've made all recommended changes. Thank you. |
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>
Submission to Project: util-linux Open Incident: util-linux#2637 at github.com/util-linux/issues/2637 Component: util-linux/sys-utils Files: tests/ts/dmesg syslog interface caller-id files, tests and related expected files Testing on Fedora 39 with Linux-6.6.6 Kernel and CONFIG_PRINTK_CALLER config option set. Patch tested and generated with the latest util-linux code pulled. Retro-fitted to merge on top of the patch for Issue: util-linux#2609 For Issue util-linux#2609 Thomas and Zak pointed out the we need tests to verify that the dmesg command works correctly and to allow us to compare the results from PRINTK_CALLER id field tests provided by util-linux#2609 with the standard (syslog interface) dmesg tests. Currently, dmesg only has standard syslog interface tests even though dmesg -S the syslog interface supports the caller_id field. There are no syslog caller-id tests. We would like syslog caller-id tests both to validate that the dmesg code works correctly with the caller-id field being present and also to compare against the addition of dmesg kmsg caller_id support added by Issue util-linux#2609. These tests are for the dmesg syslog interface with caller-id follow the existing test structure for dmesg tests. The existing dmesg -F interface is used to input our test files. Until Thomas added a dmesg kmsg interface for json format testing there were no dmesg tests except the tests for the generic dmesg syslog tests. So we're naming the syslog caller-id tests to follow the test naming convention that Thomas introduced. For caller_id tests we prefix the test name with cid- abbreviating the caller_id name to keep the names short. There is no unqiue indentifier for syslog tests, so syslog tests are currently: colors, console-levels, decode, delta, facilities, indentation, limit, json The cid versions of these test files are just prefixed with cid- The patch for Issue: util-linux#2609 has the files: cid-input and cid-json and the expected file for cide-json Additional new dmesg tests are found with Issue util-linux#2663 which add standard dmesg kmsg interface tests providing equivalent tests to the existing dmesg syslog interface tests. Also, Issue util-linux#2609 introduces dmesg kmsg interface caller-id tests equivalent to the dmesg syslog interface with caller-id tests introduced here along with the necessary dmesg kmsg interface caller-id support needed to accomodate the PRINTK_CALLER id field. Just for reference, on a Linux system with the CONFIG_PRINTK_CALLER configuration option set the output from dmesg -S looks like: [ 520.899558] [ T3919] hub 3-3:1.0: USB hub found on a system where the PRINTK_CALLER configuration option is not set the output looks like: [ 520.899558] hub 3-3:1.0: USB hub found the additional field specifies either a Thread Id or CPU id depending on the context of the task or thread at the time the printk that added the message to the kernel ring buffer was executed. Signed-off-by: Ivan Delalande <colona@arista.com> Signed-off-by: Edward Chron <echron@arista.com>
Submission to Project: util-linux Open Incident: util-linux#2663 at github.com/util-linux/issues/2663 Component: util-linux/sys-utils Files: tests/ts/dmesg kmsg interface files and related expected files Testing on Fedora 39 with Linux-6.6.6 Kernel and CONFIG_PRINTK_CALLER config option set. Patch tested and generated with the latest util-linux code pulled. Revision: no caller optional fields in any of the kmsg-input entries Revision: retrofitted to apply on top of Issue: util-linux#2609 and Issue util-linux#2637 This is patch 1 of 2 (first in the series) Second patch needed to hold second binary file (git binary files issue) For issue util-linux#2609 Thomas and Zak pointed out the we need tests to verify that the dmesg command works correctly and to allow us to compare the results from PRINTK_CALLER id field tests provided by util-linux#2609 with the standard (syslog interface) dmesg tests. Except for a kmsg json test that Thomas added recently we don't have basic dmesg tests for the kmsg interface to compare results against. We added tests for the dmesg SYSLOG PRINTK_CALLER id interface so we can compare against those tests. Those tests were submitted with Issue util-linux#2637. Those tests were created before Thomas added the new dmesg kmsg test and I will rename those tests to match the naming scheme that Thomas is using for tests that are specific to syslog interface and specific to kmsg interface. Issue util-linux#2609 introduces dmesg kmsg interface support for the PRINTK_CALLER id field and provides tests to compare against the SYSLOG interface tests added by util-linux#2637. Those tests also need to renamed to be consistent Thomas's test naming scheme. Here we've created tests for the dmesg kmsg interface following the existing test structure for dmesg tests. With the addition of this set of tests, we have tests for SYSLOG and SYSLOG PRINTK_CALLER id field to compare against the kmsg and kmsg PRINTK_CALLER id field tests. Currently the only kmsg interface specific test that exists is the kmsg-file test that Thomas added to test the dmesg kmsg interface for json support. Thomas also added code for the -K file interface to process dmesg ksmg interface files for testing so we utilize that code here and add to it. The kmsg-input file is expanded to provide statements and fields to completely test the kmsg interface with tests that are equivalent to the SYSLOG interface dmesg tests. Additionally a ksmg-newlines file is added which provides kmsg format for testing with indentation. The output of the existing kmsg-file test is adjusted to match the expanded kmsg-input file. All tests follow the standard util-linux tests format used by dmesg for unit tests. Signed-off-by: Ivan Delalande <colona@arista.com> Signed-off-by: Edward Chron <echron@arista.com>
Submission to Project: util-linux Open Incident: util-linux#2663 at github.com/util-linux/issues/2663 Component: util-linux/sys-utils Files: tests/ts/dmesg kmsg interface files and related expected files Testing on Fedora 39 with Linux-6.6.6 Kernel and CONFIG_PRINTK_CALLER config option set. Patch tested and generated with the latest util-linux code pulled. Revision: no caller optional fields in any of the kmsg-input entries Revision: retrofitted to apply on top of Issue: util-linux#2609 and Issue util-linux#2637 This is patch 2 of 2 (second in the series) A second patch needed to hold 2nd binary file (git binary files issue) This patch is needed because git format does not produce correct output if two binary files are included in the same patch. So adding the second binary file in a second patch to resolve the issue. Signed-off-by: Ivan Delalande <colona@arista.com> Signed-off-by: Edward Chron <echron@arista.com>
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>
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: util-linux#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>
Add support to standard dmesg command for the optional Linux Kernel debug CONFIG option PRINTK_CALLER field:
The printk caller field 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.
I'm attaching a gzip'ed patch file that adds support for dmesg and works with all dmesg options including -J to produce JSON output if the website allows this (says it is a supported file type). I will add the incident number that is assigned here into the patch header.
The text was updated successfully, but these errors were encountered: