Bug 215836 - [PATCH] sbin/dmesg: support new flag for watching messages
Summary: [PATCH] sbin/dmesg: support new flag for watching messages
Status: Closed Not Accepted
Alias: None
Product: Base System
Classification: Unclassified
Component: bin (show other bugs)
Version: CURRENT
Hardware: Any Any
: --- Affects Only Me
Assignee: freebsd-bugs (Nobody)
URL:
Keywords: patch
Depends on:
Blocks:
 
Reported: 2017-01-06 20:30 UTC by joe
Modified: 2017-01-08 15:46 UTC (History)
1 user (show)

See Also:


Attachments
sbin/dmesg: add -w option w/docs (1.99 KB, patch)
2017-01-06 20:30 UTC, joe
no flags Details | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description joe 2017-01-06 20:30:42 UTC
Created attachment 178581 [details]
sbin/dmesg: add -w option w/docs

This patch introduces an option -w for displaying the kernel messages, repeatedly. When combined with the -c option, it tails kernel messages.

This is invaluable for environments where accessing the live console isn't feasible; but watching the messages with as little overhead as possible is desired.

Patch includes MAN page update too.
Comment 1 Mateusz Guzik freebsd_committer freebsd_triage 2017-01-06 21:28:49 UTC
>@@ -109,6 +112,8 @@ main(int argc, char *argv[])
> 	if (argc != 0)
> 		usage();
> 
>+again:
>+
> 	if (memf == NULL) {
> 		/*
> 		 * Running kernel.  Use sysctl.  This gives an unwrapped buffer
>@@ -203,15 +208,26 @@ main(int argc, char *argv[])
> 			}
> 		}
> 
>+		if (*p == '\0') continue;
>+
> 		(void)strvisx(visbp, p, nextp - p, 0);
>-		(void)printf("%s", visbp);
>+		if (*visbp != '\n') (void)printf("%s", visbp);
> 	}
>+
>+	free (bp);
>+	free (visbp);
>+
>+	if (loop) {
>+		usleep(100000);
>+		goto again;
>+	}
>+
> 	exit(0);
> }
> 

I'm afraid this approach is a non-starter. Entries in dmesg show up extremely rarely and waking up periodically to check it quite wasteful, especially so with this frequency.

Luckily, /dev/klog supports kqueue so you can use that to get notified.
Comment 2 joe 2017-01-06 22:40:27 UTC
I agree that kqueue() is a much better solution, but I am met with an error when trying to open /dev/klog. The details are below. Any assistance on a solution would be most appreciated!

if ((klog_fd = open("/dev/klog", O_RDONLY | O_NONBLOCK | O_CLOEXEC, 0)) < 0)
	err(EXIT_FAILURE, "open");

dmesg: open: Device busy
Comment 3 Mateusz Guzik freebsd_committer freebsd_triage 2017-01-06 22:44:52 UTC
Granted, I did not know about the limitation, but it hints at a better solution here:

# procstat -fa | grep klog
  638 syslogd              8 v c r----n--   1   19977 -   /dev/klog

Since syslog already monitors dmesg, you can just inspect the log created by syslog instead of interfacing with the device.

That said, the feature itself would be nice, but busy checking for work is a non-starter and it is unlikely it is worth it to make the device openable by many threads.
Comment 4 joe 2017-01-06 23:32:44 UTC
Thank you for your feedback.

I cannot simply go through syslog, as too much delay and overhead.

I am proposing three solutions to this. Which sounds the most likely to succeed in being accepted?

1. In researching "sys/kern/subr_log.c", I see it only accepts a single process watching (as you've kindly mentioned). Since the whole point of this file is centered around read-only operations; I feel it would be safe and fairly non-complex to support multiple processes performing open() and kevent() calls by switching to a linked list of "struct selinfo". Each waiting process may then utilize kevent() mechanisms; with additional changes to the mutex calls.

2. Use the value of "kern.log_wakeups_per_second" to calculate a better sleep() call between loops.

3. Keep the dmesg change locally.

I am willing to accept any of these options, with #3 being done, #2 being very simple, and #1 being a bit involved, but supporting a number of ideas I have.

Thoughts, suggestions, or ideas are welcomed!
-Joe
Comment 5 Mateusz Guzik freebsd_committer freebsd_triage 2017-01-07 18:16:05 UTC
(In reply to joe from comment #4)

> I cannot simply go through syslog, as too much delay and overhead.

What delay and overhead do you have in mind here? Sure, reading output only after it got processed by syslog is somewhat later then reading it "instantly", but even with your patch you have worst-case 100ms delay. i.e., does not look like it is a factor here. Also you already have syslog processing all this data.

> 1. In researching "sys/kern/subr_log.c", I see it only accepts a single process watching (as you've kindly mentioned). Since the whole point of this file is centered around read-only operations; I feel it would be safe and fairly non-complex to support multiple processes performing open() and kevent() calls by switching to a linked list of "struct selinfo". Each waiting process may then utilize kevent() mechanisms; with additional changes to the mutex calls.

The problem is not with notifications but the buffer state not being per-file object. That is, distinct open()s of the file doing reads steal each others content. Thus allowing such opens would give rather surprising results. Fixing this looks non-trivial (or rather, cumbersome and worth it given supposed gains).

In principle perhaps someone would accept an "allow anyway" knob, but I'm not convinced this is the way to go here.

> 2. Use the value of "kern.log_wakeups_per_second" to calculate a better sleep() call between loops.

With the current value of 5 this is 200ms. What latency do you expect to see from syslog?

The standard model of operation is that you go to the kernel and let it wait for stuff as it sees it. Periodic wakeups of an otherwise idle process, which almost never has anything to do are a last resort. Similarly, the current in the kernel should be reworked at some point, but at least it is not a user-visible problem.

That said, my suggested way is:
1. configure syslog to log events you want to an unused tty (e.g. /dev/ttyvb)
2. use watch(8) (it requires the 'snp' kernel module) to stream events as they show up
3. ... alternatively hack up a slightly nicer tool also using the snp module

This has a somewhat cost of reading a message, but I doubt it will be visible in anything short of a microbenchmark. In the meantime, there is no thread being woken up constantly when there are no events vast majority of the time.
Comment 6 Mateusz Guzik freebsd_committer freebsd_triage 2017-01-07 18:16:47 UTC
To be clear, I would be happy to see the feature, but patching up problematic kernel components does not seem to be worth it.
Comment 7 joe 2017-01-08 15:46:35 UTC
Thank you very much for the feedback!