[PATCH shepherd] shepherd: If /dev/kmsg is writable, use it for logging.

  • Done
  • quality assurance status badge
Details
2 participants
  • Danny Milosavljevic
  • Ludovic Courtès
Owner
unassigned
Submitted by
Danny Milosavljevic
Severity
normal
D
D
Danny Milosavljevic wrote on 17 Feb 2018 13:20
(address . guix-patches@gnu.org)(name . Danny Milosavljevic)(address . dannym@scratchpost.org)
20180217122035.1443-1-dannym@scratchpost.org
* modules/shepherd.scm (main): If /dev/kmsg is used, don't log to console
again - use only /dev/kmsg.
* modules/shepherd/comm.scm (%current-logfile-date-format): New variable.
(make-shepherd-output-port): Use it. Export.
* modules/shepherd/support.scm (default-logfile-date-format): New variable.
(default-logfile): Use /dev/kmsg if writable.
(default-logfile-date-format): Drop duplicate timestamp.
---
modules/shepherd.scm | 6 +++++-
modules/shepherd/comm.scm | 11 ++++++-----
modules/shepherd/support.scm | 11 ++++++++++-
3 files changed, 21 insertions(+), 7 deletions(-)

Toggle diff (96 lines)
diff --git a/modules/shepherd.scm b/modules/shepherd.scm
index 5334657..2db56a1 100644
--- a/modules/shepherd.scm
+++ b/modules/shepherd.scm
@@ -141,8 +141,12 @@
;; Enable logging as first action.
(start-logging logfile)
+ (if (string=? logfile "/dev/kmsg")
+ ;; Prevent duplicate messages.
+ (set-current-output-port (%make-void-port "w")))
+
;; Send output to log and clients.
- (set-current-output-port shepherd-output-port)
+ (set-current-output-port (make-shepherd-output-port (current-output-port)))
;; Start the 'root' service.
(start root-service)
diff --git a/modules/shepherd/comm.scm b/modules/shepherd/comm.scm
index 0228f63..6cea6f0 100644
--- a/modules/shepherd/comm.scm
+++ b/modules/shepherd/comm.scm
@@ -51,7 +51,8 @@
start-logging
stop-logging
%current-client-socket
- shepherd-output-port))
+ %current-logfile-date-format
+ make-shepherd-output-port))
;; Command for shepherd.
@@ -200,6 +201,9 @@ on service '~a':")
;; Socket of the client currently talking to the daemon.
(make-parameter #f))
+(define %current-logfile-date-format
+ (make-parameter default-logfile-date-format))
+
;; We provide our own output mechanism, because we have certain
;; special needs; most importantly, we want to send output to herd
;; sometimes.
@@ -228,7 +232,7 @@ on service '~a':")
(let* ((log (lambda (x)
(display x log-output-port)))
(init-line (lambda ()
- (log (strftime "%Y-%m-%d %H:%M:%S "
+ (log (strftime (%current-logfile-date-format)
(localtime (current-time)))))))
(init-line)
(for-each log (reverse buffer))
@@ -259,6 +263,3 @@ on service '~a':")
;; It's an output-only port.
"w"))
-
-(define shepherd-output-port
- (make-shepherd-output-port (current-output-port)))
diff --git a/modules/shepherd/support.scm b/modules/shepherd/support.scm
index bb01edc..585aef9 100644
--- a/modules/shepherd/support.scm
+++ b/modules/shepherd/support.scm
@@ -22,6 +22,7 @@
(define-module (shepherd support)
#:use-module (shepherd config)
#:use-module (ice-9 match)
+ #:use-module (ice-9 format)
#:export (call/ec
caught-error
assert
@@ -43,6 +44,7 @@
user-homedir
default-logfile
+ default-logfile-date-format
default-config-file
default-socket-dir
default-socket-file
@@ -282,9 +284,16 @@ TARGET should be a string representing a filepath + name."
;; Logfile.
(define default-logfile
(if (zero? (getuid))
- (string-append %localstatedir "/log/shepherd.log")
+ (if (access? "/dev/kmsg" W_OK)
+ "/dev/kmsg"
+ (string-append %localstatedir "/log/shepherd.log"))
(string-append %user-config-dir "/shepherd.log")))
+(define default-logfile-date-format
+ (if (and (zero? (getuid)) (string=? default-logfile "/dev/kmsg"))
+ (format #f "shepherd[~d]: " (getpid))
+ "%Y-%m-%d %H:%M:%S "))
+
;; Configuration file.
(define (default-config-file)
"Return the default configuration file---either the user's file, or the
D
D
Danny Milosavljevic wrote on 17 Feb 2018 13:25
(address . 30498@debbugs.gnu.org)
20180217132512.7e895e87@scratchpost.org
It's nice to be able to correlate all the stuff that happens at startup now:

Now you can actually see the communication between the processes sometimes :)

Example output:

$ dmesg
...
[ 2.893529] usb 1-6: Manufacturer: Chicony Electronics Co., Ltd.
[ 3.056972] shepherd[1]: Service root has been started.
[ 3.456744] shepherd[1]: starting services...
[ 3.457110] shepherd[1]: Service root-file-system has been started.
[ 3.466479] shepherd[1]: waiting for udevd...
[ 3.522308] udevd[186]: starting version 3.2.2
[ 3.574506] udevd[186]: starting eudev-3.2.2
[ 3.967420] udevd[186]: no sender credentials received, message ignored
[ 4.030350] Non-volatile memory driver v1.3
[ 4.059448] thinkpad_acpi: ThinkPad ACPI Extras v0.25
...
[ 5.298348] ath9k_htc 2-2:1.0 wlp0s29f7u2: renamed from wlan0
[ 5.381098] fbcon: inteldrmfb (fb0) is primary device
[ 5.938603] Console: switching to colour frame buffer device 160x50
[ 5.958004] i915 0000:00:02.0: fb0: inteldrmfb frame buffer device
[ 5.993028] shepherd[1]: Service udev has been started.
[ 10.953719] Btrfs loaded, crc32c=crc32c-generic
[ 10.955704] BTRFS: device label dayas-home devid 1 transid 260833 /dev/dm-0
[ 10.983703] shepherd[1]: Service device-mapping-dayas-home has been started.
[ 10.984000] shepherd[1]: Service user-file-systems has been started.
[ 11.049660] BTRFS info (device dm-0): disk space caching is enabled
[ 11.049663] BTRFS info (device dm-0): has skinny extents
[ 11.219716] BTRFS info (device dm-0): enabling ssd optimizations
[ 11.236633] shepherd[1]: Service file-system-/home has been started.
[ 11.237366] shepherd[1]: Service file-system-/dev/pts has been started.
[ 11.237997] shepherd[1]: Service file-system-/dev/shm has been started.
[ 11.238568] shepherd[1]: Service file-system-/gnu/store has been started.
[ 11.239180] shepherd[1]: Service file-system-/run/systemd has been started.
[ 11.239839] shepherd[1]: Service file-system-/run/user has been started.
[ 11.240465] shepherd[1]: Service file-system-/sys/fs/cgroup has been started.
[ 11.241261] shepherd[1]: Service file-system-/sys/fs/cgroup/elogind has been started.
[ 16.538532] shepherd[1]: Respawning thermald.
...
[ 21.862151] IPv6: ADDRCONF(NETDEV_CHANGE): wlp0s29f7u2: link becomes ready
[ 345.176995] shepherd[1]: Respawning xorg-server.
[ 345.178541] shepherd[1]: Service xorg-server has been started.
[ 764.782498] perf: interrupt took too long (2526 > 2500), lowering kernel.perf_event_max_sample_rate to 79000
D
D
Danny Milosavljevic wrote on 17 Feb 2018 17:48
[WIP v2 shepherd] shepherd: If /dev/kmsg is writable, use it for logging.
(address . 30498@debbugs.gnu.org)(name . Danny Milosavljevic)(address . dannym@scratchpost.org)
20180217164835.1178-1-dannym@scratchpost.org
* modules/shepherd.scm (main): If /dev/kmsg is used, don't log to console
again - use only /dev/kmsg. Also redirect stderr to /dev/kmsg in
that case.
* modules/shepherd/comm.scm (%current-logfile-date-format): New variable.
(make-shepherd-output-port): Use it. Export.
* modules/shepherd/support.scm (default-logfile-date-format): New variable.
(default-logfile): Use /dev/kmsg if writable.
(default-logfile-date-format): Drop duplicate timestamp.
---
modules/shepherd.scm | 10 +++++++++-
modules/shepherd/comm.scm | 20 ++++++++++++--------
modules/shepherd/support.scm | 11 ++++++++++-
3 files changed, 31 insertions(+), 10 deletions(-)

Toggle diff (124 lines)
diff --git a/modules/shepherd.scm b/modules/shepherd.scm
index 5334657..2893143 100644
--- a/modules/shepherd.scm
+++ b/modules/shepherd.scm
@@ -141,12 +141,20 @@
;; Enable logging as first action.
(start-logging logfile)
+ (if (string=? logfile "/dev/kmsg")
+ ;; Prevent duplicate messages.
+ (set-current-output-port (%make-void-port "w")))
+
;; Send output to log and clients.
- (set-current-output-port shepherd-output-port)
+ (set-current-output-port
+ (make-shepherd-output-port (current-output-port)))
;; Start the 'root' service.
(start root-service)
+ (set-current-error-port
+ (make-shepherd-output-port (current-error-port) (const #f)))
+
;; This _must_ succeed. (We could also put the `catch' around
;; `main', but it is often useful to get the backtrace, and
;; `caught-error' does not do this yet.)
diff --git a/modules/shepherd/comm.scm b/modules/shepherd/comm.scm
index 0228f63..dc7d740 100644
--- a/modules/shepherd/comm.scm
+++ b/modules/shepherd/comm.scm
@@ -51,7 +51,8 @@
start-logging
stop-logging
%current-client-socket
- shepherd-output-port))
+ %current-logfile-date-format
+ make-shepherd-output-port))
;; Command for shepherd.
@@ -200,10 +201,16 @@ on service '~a':")
;; Socket of the client currently talking to the daemon.
(make-parameter #f))
+(define %current-logfile-date-format
+ (make-parameter default-logfile-date-format))
+
;; We provide our own output mechanism, because we have certain
;; special needs; most importantly, we want to send output to herd
;; sometimes.
-(define (make-shepherd-output-port original-output-port)
+(define* (make-shepherd-output-port original-output-port
+ #:optional
+ (current-client-socket-thunk
+ %current-client-socket))
(make-soft-port
(vector
@@ -216,9 +223,9 @@ on service '~a':")
(lambda (str)
;; When herd is connected, send it the output; otherwise, in the
;; unlikely case nobody is listening, send to the standard output.
- (if (%current-client-socket)
+ (if (current-client-socket-thunk)
(catch-system-error
- (display str (%current-client-socket)))
+ (display str (current-client-socket-thunk)))
(display str original-output-port))
;; Logfile, buffer line-wise and output time for each
@@ -228,7 +235,7 @@ on service '~a':")
(let* ((log (lambda (x)
(display x log-output-port)))
(init-line (lambda ()
- (log (strftime "%Y-%m-%d %H:%M:%S "
+ (log (strftime (%current-logfile-date-format)
(localtime (current-time)))))))
(init-line)
(for-each log (reverse buffer))
@@ -259,6 +266,3 @@ on service '~a':")
;; It's an output-only port.
"w"))
-
-(define shepherd-output-port
- (make-shepherd-output-port (current-output-port)))
diff --git a/modules/shepherd/support.scm b/modules/shepherd/support.scm
index bb01edc..585aef9 100644
--- a/modules/shepherd/support.scm
+++ b/modules/shepherd/support.scm
@@ -22,6 +22,7 @@
(define-module (shepherd support)
#:use-module (shepherd config)
#:use-module (ice-9 match)
+ #:use-module (ice-9 format)
#:export (call/ec
caught-error
assert
@@ -43,6 +44,7 @@
user-homedir
default-logfile
+ default-logfile-date-format
default-config-file
default-socket-dir
default-socket-file
@@ -282,9 +284,16 @@ TARGET should be a string representing a filepath + name."
;; Logfile.
(define default-logfile
(if (zero? (getuid))
- (string-append %localstatedir "/log/shepherd.log")
+ (if (access? "/dev/kmsg" W_OK)
+ "/dev/kmsg"
+ (string-append %localstatedir "/log/shepherd.log"))
(string-append %user-config-dir "/shepherd.log")))
+(define default-logfile-date-format
+ (if (and (zero? (getuid)) (string=? default-logfile "/dev/kmsg"))
+ (format #f "shepherd[~d]: " (getpid))
+ "%Y-%m-%d %H:%M:%S "))
+
;; Configuration file.
(define (default-config-file)
"Return the default configuration file---either the user's file, or the
D
D
Danny Milosavljevic wrote on 17 Feb 2018 17:49
(address . 30498@debbugs.gnu.org)
20180217174958.3fc12621@scratchpost.org
(WIP because the cryptsetup passphrase entry prompt is now invisible. Oops?
Works if one blindly enters it, though)
L
L
Ludovic Courtès wrote on 26 Feb 2018 19:04
Re: [bug#30498] [WIP v2 shepherd] shepherd: If /dev/kmsg is writable, use it for logging.
(name . Danny Milosavljevic)(address . dannym@scratchpost.org)(address . 30498@debbugs.gnu.org)
87muzvtyo3.fsf@gnu.org
Hi!

Danny Milosavljevic <dannym@scratchpost.org> skribis:

Toggle quote (9 lines)
> * modules/shepherd.scm (main): If /dev/kmsg is used, don't log to console
> again - use only /dev/kmsg. Also redirect stderr to /dev/kmsg in
> that case.
> * modules/shepherd/comm.scm (%current-logfile-date-format): New variable.
> (make-shepherd-output-port): Use it. Export.
> * modules/shepherd/support.scm (default-logfile-date-format): New variable.
> (default-logfile): Use /dev/kmsg if writable.
> (default-logfile-date-format): Drop duplicate timestamp.

[...]

Toggle quote (10 lines)
> --- a/modules/shepherd.scm
> +++ b/modules/shepherd.scm
> @@ -141,12 +141,20 @@
> ;; Enable logging as first action.
> (start-logging logfile)
>
> + (if (string=? logfile "/dev/kmsg")
> + ;; Prevent duplicate messages.
> + (set-current-output-port (%make-void-port "w")))

Nitpick: I’d use ‘when’ here since there’s no ‘else’ branch.

Toggle quote (3 lines)
> +(define %current-logfile-date-format
> + (make-parameter default-logfile-date-format))

Please add a one-line comment explaining what the format is.

Could you also add a couple of lines in the .texi file explaining that
/dev/kmsg is used when it’s available and we’re running as root?

As for cryptsetup, what if the service that runs crypsetup simply
parameterizes ‘log-output-port’ to /dev/console? That would give us the
current behavior, right?

Apart from that it LGTM, thank you!

Ludo’.
D
D
D
Danny Milosavljevic wrote on 26 Feb 2018 23:32
(name . Ludovic Courtès)(address . ludo@gnu.org)(address . 30498@debbugs.gnu.org)
20180226233214.6fe40fa3@scratchpost.org
Hi Ludo,

Toggle quote (4 lines)
> As for cryptsetup, what if the service that runs crypsetup simply
> parameterizes ‘log-output-port’ to /dev/console? That would give us the
> current behavior, right?

I don't understand why this current-output-port stuff is somehow passed on to
forked processes in the first place (why does cryptsetup care what I do
to guile variables?).

scheme@(guile-user)> (current-output-port (%make-void-port "w"))
scheme@(guile-user)> (system* "ls" "/")
scheme@(guile-user)>

WTF?

It wasn't my intention to inherit them as file descriptors... also, for guile
buffering ports, how does it inherit those as file descriptors? Will it still
do the custom line buffering that shepherd does, also when a child process
writes there?
L
L
Ludovic Courtès wrote on 27 Feb 2018 10:19
(name . Danny Milosavljevic)(address . dannym@scratchpost.org)(address . 30498@debbugs.gnu.org)
87inai6b7w.fsf@gnu.org
Hi Danny,

Danny Milosavljevic <dannym@scratchpost.org> skribis:

Toggle quote (12 lines)
>> As for cryptsetup, what if the service that runs crypsetup simply
>> parameterizes ‘log-output-port’ to /dev/console? That would give us the
>> current behavior, right?
>
> I don't understand why this current-output-port stuff is somehow passed on to
> forked processes in the first place (why does cryptsetup care what I do
> to guile variables?).
>
> scheme@(guile-user)> (current-output-port (%make-void-port "w"))
> scheme@(guile-user)> (system* "ls" "/")
> scheme@(guile-user)>

Funny no? :-)

This is in libguile/posix.c, ‘scm_open_process’ and ‘start_child’: when
the current input/output/error port isn’t a file port, FDs 0/1/2 in the
child are made to point to /dev/null. Otherwise, they are inherited as
file descriptors.

For cryptsetup, this should be what we want if we do:

(call-with-output-file "/dev/console"
(lambda (port)
(parameterize ((log-output-port port)
(current-input-port port)
(current-error-port port))
(invoke "cryptsetup" …))))

Or do we even need to care about ‘log-output-port’? Thoughts?

Toggle quote (5 lines)
> It wasn't my intention to inherit them as file descriptors... also, for guile
> buffering ports, how does it inherit those as file descriptors? Will it still
> do the custom line buffering that shepherd does, also when a child process
> writes there?

Shepherd does not process the stdout/err of child processes in any way,
so there shouldn’t be buffering there.

Ludo’.
L
L
Ludovic Courtès wrote on 27 Feb 2018 10:22
(name . Danny Milosavljevic)(address . dannym@scratchpost.org)(address . 30498@debbugs.gnu.org)
87efl66b3f.fsf@gnu.org
Hi!

Danny Milosavljevic <dannym@scratchpost.org> skribis:

Toggle quote (15 lines)
> From 40426570679e83fff25eadbcc20476ebc321740f Mon Sep 17 00:00:00 2001
> From: Danny Milosavljevic <dannym@scratchpost.org>
> Date: Sat, 17 Feb 2018 17:44:34 +0100
> Subject: [PATCH v2] shepherd: If /dev/kmsg is writable, use it for logging.
> Tags: patch
>
> * modules/shepherd.scm (main): If /dev/kmsg is used, don't log to console
> again - use only /dev/kmsg. Also redirect stderr to /dev/kmsg in
> that case.
> * modules/shepherd/comm.scm (%current-logfile-date-format): New variable.
> (make-shepherd-output-port): Use it. Export.
> * modules/shepherd/support.scm (default-logfile-date-format): New variable.
> (default-logfile): Use /dev/kmsg if writable.
> (default-logfile-date-format): Drop duplicate timestamp.
> * doc/shepherd.texi (logging): Document /dev/kmsg.
^
“Logging”.

Toggle quote (10 lines)
> --- a/doc/shepherd.texi
> +++ b/doc/shepherd.texi
> @@ -405,7 +405,8 @@ permissions are not as expected.
> @cindex logging
> @cindex log file
> Log output into @var{file}, or if @var{file} is not given,
> -@code{/var/log/shepherd.log} when running as superuser,
> +@code{/dev/kmsg} when running as superuser (except when this is not possible --
> +then it uses @code{/var/log/shepherd.log}),

Nitpick: it should be three hyphens without surrounding spaces, leading
to an em dash, “like---this”.

Let’s just make sure we have a solution for cryptsetup and then you’re
welcome to push it to shepherd.git!

Thank you,
Ludo’.
L
L
Ludovic Courtès wrote on 3 Mar 2018 22:54
(name . Danny Milosavljevic)(address . dannym@scratchpost.org)(address . 30498@debbugs.gnu.org)
87bmg46d10.fsf@gnu.org
Hey Danny,

Looks like we’ve accumulated stuff that justifies a new Shepherd release
this time. It’d be nice if we could get this patch in as well! What
are we missing?

Ludo’.
D
D
Danny Milosavljevic wrote on 3 Mar 2018 23:37
(name . Ludovic Courtès)(address . ludo@gnu.org)(address . 30498@debbugs.gnu.org)
20180303233715.7ec8a08c@scratchpost.org
I think that just something like this is missing:

Toggle diff (58 lines)
diff --git a/modules/shepherd/service.scm b/modules/shepherd/service.scm
index 83600e4..481203d 100644
--- a/modules/shepherd/service.scm
+++ b/modules/shepherd/service.scm
@@ -728,20 +728,37 @@ false."
;; it for something unrelated, which can confuse some packages.
(dup2 (open-fdes "/dev/null" O_RDONLY) 0)
- (when log-file
- (catch #t
- (lambda ()
- ;; Redirect stout and stderr to use LOG-FILE.
- (catch-system-error (close-fdes 1))
- (catch-system-error (close-fdes 2))
- (dup2 (open-fdes log-file (logior O_CREAT O_WRONLY)) 1)
- (dup2 (open-fdes log-file (logior O_CREAT O_WRONLY)) 2))
- (lambda (key . args)
- (format (current-error-port)
- "failed to open log-file ~s:~%" log-file)
- (print-exception (current-error-port) #f key args)
- (primitive-exit 1))))
-
+ (if log-file
+ (catch #t
+ (lambda ()
+ ;; Redirect stout and stderr to use LOG-FILE.
+ (catch-system-error (close-fdes 1))
+ (catch-system-error (close-fdes 2))
+ (dup2 (open-fdes log-file (logior O_CREAT O_WRONLY)) 1)
+ (dup2 (open-fdes log-file (logior O_CREAT O_WRONLY)) 2))
+ (lambda (key . args)
+ (format (current-error-port)
+ "failed to open log-file ~s:~%" log-file)
+ (print-exception (current-error-port) #f key args)
+ (primitive-exit 1)))
+ (catch #t
+ (lambda ()
+ ;; Make sure the child has stdout/stderr that can be used.
+ ;; We sometimes set current-error-port to a softport.
+ ;; libguile would then autoconnect /dev/null -
+ ;; which we don't want.
+ ;; Also, cryptsetup interactively asks for a password,
+ ;; so we don't want /dev/kmsg either.
+ ;; In a user shepherd all this is not necessary -
+ ;; but then, port->fdes will not fail.
+ (when (not (false-if-exception (port->fdes (current-output-port))))
+ (dup2 (open-fdes "/dev/console" (logior O_WRONLY)) 1))
+ (when (not (false-if-exception (port->fdes (current-error-port))))
+ (dup2 (open-fdes "/dev/console" (logior O_WRONLY)) 2)))
+ (lambda (key . args)
+ (format (current-error-port) "failed to open stdout/stderr\n")
+ (print-exception (current-error-port) #f key args)
+ (primitive-exit 1))))
(let loop ((i 3))
(when (< i max-fd)
;; First try to close any ports associated with file descriptor I.

Patch starting from master attached for convenience.
-----BEGIN PGP SIGNATURE-----

iQEzBAEBCAAdFiEEds7GsXJ0tGXALbPZ5xo1VCwwuqUFAlqbI5sACgkQ5xo1VCww
uqWvwgf/WpjVhzjdtyUrbgBy57DT+lHn7YSJbzIlolWnTu8EVKt2e6Ejr78xkaWH
hpyH1SxklOeVO38FO5uC+pbn7sagfTuYfOzhFtP76rQzCBHYf/8q1Dqw6VFqdHrq
cHfFTACgVzjfJz/DNEZPKdpwQ5lfK4CDHET5EC3oZL0G/kGdm/caLVhBwqaQNrFD
EbW3hkdbWqpUB70cdWloVitgI58jlH0nhZChfVGWvFVN9ZoTVEm67S5pOfOT+Pl6
a4A3tldtmiPlRQbxFqqE5yZ0g8twrtSDv6rycnFYduv6uX5JelOZSeNjHZDIPM9X
x6gAUzi0lymib7grPhBGAZD+B42JTA==
=kF9P
-----END PGP SIGNATURE-----


L
L
Ludovic Courtès wrote on 5 Mar 2018 17:51
(name . Danny Milosavljevic)(address . dannym@scratchpost.org)(address . 30498@debbugs.gnu.org)
87371ea2jj.fsf@gnu.org
Heya,

I took the liberty to split this in several patches, which I think makes
it easier to follow. I omitted the bits about redirecting stderr, for
now, to simplify things.

I tested it in a GuixSD VM and it works as advertised! \o/

There’s one thing we need to improve though: syslogd reads /proc/kmsg
and prefixes everything that comes from there with “vmunix” (as if it
came from the kernel). That’s inconvenient because it makes it
impossible to have syslogd rules to filter shepherd messages.

So I think we need to do instead use a ‘syslog’-style interface and,
similar to what ‘syslog’ does in glibc, write to /dev/log unless it’s
unavailable, in which case we fall back to /dev/kmsg.

Thoughts?

I’ll see if I can give it a try.

Thanks,
Ludo’.
D
D
Danny Milosavljevic wrote on 6 Mar 2018 09:09
(name . Ludovic Courtès)(address . ludo@gnu.org)(address . 30498@debbugs.gnu.org)
20180306090905.77f528a9@scratchpost.org
Hi,

On Mon, 05 Mar 2018 17:51:44 +0100
ludo@gnu.org (Ludovic Courtès) wrote:
Toggle quote (2 lines)
> I tested it in a GuixSD VM and it works as advertised! \o/

Yay!

Toggle quote (4 lines)
> There’s one thing we need to improve though: syslogd reads /proc/kmsg
> and prefixes everything that comes from there with “vmunix” (as if it
> came from the kernel).

Also, apparently syslogd uses the timestamp of "when it read the messages
out of /dev/kmsg" as syslog entry timestamp *although* /dev/kmsg contains its
own timestamps (as offsets-from-bootup). Hrmmm...

Toggle quote (3 lines)
>That’s inconvenient because it makes it
> impossible to have syslogd rules to filter shepherd messages.

I've added a shepherd "prefix" in the shepherd messages, so it should
end up as "vmunix: shepherd[1]: ..." (or so).

The somewhat heavyhanded way to fix it would be to replace

strcpy (line, "vmunix: ");

by

strcpy (line, "");

in inetutils-1.9.4/src/syslogd.c . Or use another syslogd :)

According to the Linux kernel documentation the /dev/kmsg ring buffer is
specifically allowed to be used by user processes (although they must not
impersonate the kernel - if they try, the specified priority is ignored),
so we're in the clear there.

Toggle quote (4 lines)
> So I think we need to do instead use a ‘syslog’-style interface and,
> similar to what ‘syslog’ does in glibc, write to /dev/log unless it’s
> unavailable, in which case we fall back to /dev/kmsg.

Yes, in the long run, we should do that. I think for this shepherd
release it would be fine to use only /dev/kmsg - it's still an
improvement - and the risk that we introduced a new bug by this is
basically nonexistent.

Later on, we should use /dev/log and fall back to /dev/kmsg and
then again use /dev/log as it gets available etc. I'm not sure
how to do the synchronisation (from shepherd's point of view,
syslogd asynchronously reads from /dev/kmsg and puts the messages
into its output files - so if we write to /dev/kmsg, then to
/dev/log, then to /dev/kmsg, then to /dev/log, is the message order
guaranteed?)

Toggle quote (2 lines)
>I’ll see if I can give it a try.

Thanks :)
-----BEGIN PGP SIGNATURE-----

iQEzBAEBCAAdFiEEds7GsXJ0tGXALbPZ5xo1VCwwuqUFAlqeTKEACgkQ5xo1VCww
uqUBXQgAmNwQh/An5wPAfhFKO4FwnRpdlRcIAP2HbFwQsr/VLOp639tREQM/bSYg
T+IoTLPkFy0a/8jCI/xpOfK7HjPGtRRNQ7Dvj+i//yfukGCkuDOvoNH4+rEPKObL
Av4AOfBenL8GUAuiKMkn4EXkz4FFdmdXSApLGtvvceK094B1xsvTdlyIzXKDwS5J
NzZjii5GZ9y6G8dtwQoVnB80ukcAEHrozGMof8wLGhvqg4LR5rm7F/uK/XuFkezy
hXegQ0hDZ4p37/dS+u7zvZ+O115OsK6leAJ+vBgoWzLv5hOENmuyD1jkNvnalGIR
lhluoxEwpxQYl3EToaiFsJOIc3uQmg==
=6BVe
-----END PGP SIGNATURE-----


L
L
Ludovic Courtès wrote on 7 Mar 2018 12:04
[PATCH 2/3] Simplify 'make-shepherd-output-port'.
(address . 30498@debbugs.gnu.org)
20180307110454.17110-3-ludo@gnu.org
* modules/shepherd/comm.scm (%not-newline): New variable.
(make-shepherd-output-port): Rewrite second method to simplify and make
a single 'display' call per line.
---
modules/shepherd/comm.scm | 36 ++++++++++++++++--------------------
1 file changed, 16 insertions(+), 20 deletions(-)

Toggle diff (56 lines)
diff --git a/modules/shepherd/comm.scm b/modules/shepherd/comm.scm
index 596a258..e686bfa 100644
--- a/modules/shepherd/comm.scm
+++ b/modules/shepherd/comm.scm
@@ -216,6 +216,9 @@ on service '~a':")
;; 'strftime' format strings for entries in the log file.
(make-parameter default-logfile-date-format))
+(define %not-newline
+ (char-set-complement (char-set #\newline)))
+
;; We provide our own output mechanism, because we have certain
;; special needs; most importantly, we want to send output to herd
;; sometimes.
@@ -242,26 +245,19 @@ on service '~a':")
;; completed line.
(if (not (string-index str #\newline))
(set! buffer (cons str buffer))
- (let* ((log (lambda (x)
- (display x (log-output-port))))
- (init-line (lambda ()
- (log (strftime (%current-logfile-date-format)
- (localtime (current-time)))))))
- (init-line)
- (for-each log (reverse buffer))
- (let* ((lines (string-split str #\newline))
- (last-line (car (take-right lines 1)))
- (is-first #t))
- (for-each (lambda (line)
- (if is-first
- (set! is-first #f)
- (init-line))
- (log line)
- (log #\newline))
- (drop-right lines 1))
- (set! buffer (if (string-null? last-line)
- '()
- (list last-line))))))))
+ (let* ((str (string-concatenate-reverse (cons str buffer)))
+ (lines (string-tokenize str %not-newline)))
+ (define prefix
+ (strftime (%current-logfile-date-format)
+ (localtime (current-time))))
+
+ ;; Make exactly one 'display' call per line to make sure we
+ ;; don't create several entries for each line.
+ (for-each (lambda (line)
+ (display (string-append prefix line "\n")
+ (log-output-port)))
+ lines)
+ (set! buffer '())))))
;; Flush output.
(lambda ()
--
2.16.2
L
L
Ludovic Courtès wrote on 7 Mar 2018 12:04
[PATCH 0/3] Log to syslog whenever possible
(address . 30498@debbugs.gnu.org)
20180307110454.17110-1-ludo@gnu.org
Hello!

These patches allow shepherd to use syslog, when /dev/log is reachable,
and to fall back to /dev/kmsg otherwise.

That leads to unified logging, which is nice. By looking at
/var/log/messages one can see the sequence of events, which is often
more convenient than having to look at separate log files. And we can
filter things via syslogd’s config.

However! The downside is that messages upon shutdown written after
syslogd has been killed are lost: they go to /dev/kmsg, which goes to
the console at that point, but they’re not written anywhere.

Until now, everything until the root file system is unmounted (see
‘stop-logging’ call in (gnu services base)) would be written to
/var/log/shepherd.log, which is useful to debug shutdown (that’s how I
discovered the issue fixed by Guix commit
6c4458172d12dbda969c2eae5b3b6be19a068780, for instance.)

So, I don’t know. Can we do better? Should we switch to
/var/log/shepherd.log when syslogd disappears? Ideas? That’s a
situation where having syslogd inside PID 1 helps…

Ludo’.

Ludovic Courtès (3):
Turn 'log-output-port' into a parameter.
Simplify 'make-shepherd-output-port'.
Use syslog for logging when running as root.

doc/shepherd.texi | 18 +++-
modules/shepherd.scm | 209 +++++++++++++++++++++++--------------------
modules/shepherd/comm.scm | 119 ++++++++++++++++++------
modules/shepherd/support.scm | 19 ++--
4 files changed, 224 insertions(+), 141 deletions(-)

--
2.16.2
L
L
Ludovic Courtès wrote on 7 Mar 2018 12:04
[PATCH 1/3] Turn 'log-output-port' into a parameter.
(address . 30498@debbugs.gnu.org)
20180307110454.17110-2-ludo@gnu.org
* modules/shepherd/comm.scm (log-output-port): Turn into a parameter and
publish it.
(start-logging, stop-logging): Adjust accordingly and mark as deprecated.
(make-shepherd-output-port): Adjust accordingly.
* modules/shepherd/support.scm (default-logfile): Remove.
(user-default-log-file): New procedure.
(default-logfile-date-format): Remove 'if'.
* modules/shepherd.scm (main): Have LOGFILE default to #f. Parameterize
'log-output-port' and 'current-output-port'.
---
modules/shepherd.scm | 209 +++++++++++++++++++++++--------------------
modules/shepherd/comm.scm | 19 ++--
modules/shepherd/support.scm | 19 ++--
3 files changed, 129 insertions(+), 118 deletions(-)

Toggle diff (331 lines)
diff --git a/modules/shepherd.scm b/modules/shepherd.scm
index c869464..39fbe14 100644
--- a/modules/shepherd.scm
+++ b/modules/shepherd.scm
@@ -21,6 +21,7 @@
(define-module (shepherd)
#:use-module (ice-9 match)
+ #:use-module (ice-9 format)
#:use-module (ice-9 rdelim) ;; Line-based I/O.
#:autoload (ice-9 readline) (activate-readline) ;for interactive use
#:use-module (oop goops) ;; Defining classes and methods.
@@ -77,7 +78,7 @@
(socket-file default-socket-file)
(pid-file #f)
(secure #t)
- (logfile default-logfile))
+ (logfile #f))
;; Process command line arguments.
(process-args (program-name) args
""
@@ -161,104 +162,116 @@
;; We do this early so that we can abort early if necessary.
(and socket-file
(verify-dir (dirname socket-file) #:secure? secure))
- ;; Enable logging as first action.
- (start-logging logfile)
-
- (when (string=? logfile "/dev/kmsg")
- ;; By default we'd write both to /dev/kmsg and to stdout. Redirect
- ;; stdout to the bitbucket so we don't log twice.
- (set-current-output-port (%make-void-port "w")))
-
- ;; Send output to log and clients.
- (set-current-output-port (make-shepherd-output-port))
-
- ;; Start the 'root' service.
- (start root-service)
-
- ;; This _must_ succeed. (We could also put the `catch' around
- ;; `main', but it is often useful to get the backtrace, and
- ;; `caught-error' does not do this yet.)
- (catch #t
- (lambda ()
- (load-in-user-module (or config-file (default-config-file))))
- (lambda (key . args)
- (caught-error key args)
- (quit 1)))
- ;; Start what was started last time.
- (and persistency
- (catch 'system-error
- (lambda ()
- (start-in-order (read (open-input-file
- persistency-state-file))))
- (lambda (key . args)
- (apply format #f (gettext (cadr args)) (caddr args))
- (quit 1))))
-
- (when (provided? 'threads)
- ;; XXX: This terrible hack allows us to make sure that signal handlers
- ;; get a chance to run in a timely fashion. Without it, after an EINTR,
- ;; we could restart the accept(2) call below before the corresponding
- ;; async has been queued. See the thread at
- ;; <https://lists.gnu.org/archive/html/guile-devel/2013-07/msg00004.html>.
- (sigaction SIGALRM (lambda _ (alarm 1)))
- (alarm 1))
-
- ;; Stop everything when we get SIGINT. When running as PID 1, that means
- ;; rebooting; this is what happens when pressing ctrl-alt-del, see
- ;; ctrlaltdel(8).
- (sigaction SIGINT
- (lambda _
- (stop root-service)))
- ;; Stop everything when we get SIGTERM.
- (sigaction SIGTERM
- (lambda _
- (stop root-service)))
-
- ;; Stop everything when we get SIGHUP.
- (sigaction SIGHUP
- (lambda _
- (stop root-service)))
-
- ;; Ignore SIGPIPE so that we don't die if a client closes the connection
- ;; prematurely.
- (sigaction SIGPIPE SIG_IGN)
-
- (if (not socket-file)
- ;; Get commands from the standard input port.
- (process-textual-commands (current-input-port))
- ;; Process the data arriving at a socket.
- (let ((sock (open-server-socket socket-file))
-
- ;; With Guile <= 2.0.9, we can get a system-error exception for
- ;; EINTR, which happens anytime we receive a signal, such as
- ;; SIGCHLD. Thus, wrap the 'accept' call.
- (accept (EINTR-safe accept)))
-
- ;; Possibly write out our PID, which means we're ready to accept
- ;; connections. XXX: What if we daemonized already?
- (match pid-file
- ((? string? file)
- (with-atomic-file-output pid-file
- (cute display (getpid) <>)))
- (#t (display (getpid)))
- (_ #t))
-
- (let next-command ()
- (define (read-from sock)
- (match (accept sock)
- ((command-source . client-address)
- (setvbuf command-source _IOFBF 1024)
- (process-connection command-source))
- (_ #f)))
- (match (select (list sock) (list) (list) (if poll-services? 0.5 #f))
- (((sock) _ _)
- (read-from sock))
- (_
- #f))
- (when poll-services?
- (check-for-dead-services))
- (next-command))))))
+ ;; Enable logging as first action.
+ (parameterize ((log-output-port
+ (cond (logfile
+ (open-file logfile "al"))
+ ((zero? (getuid))
+ (open-file "/dev/kmsg" "wl"))
+ (else
+ (open-file (user-default-log-file) "al"))))
+ (%current-logfile-date-format
+ (if (and (not logfile) (zero? (getuid)))
+ (format #f "shepherd[~d]: " (getpid))
+ default-logfile-date-format))
+ (current-output-port
+ ;; Send output to log and clients.
+ (make-shepherd-output-port
+ (if (and (zero? (getuid)) (not logfile))
+ ;; By default we'd write both to /dev/kmsg and to
+ ;; stdout. Redirect stdout to the bitbucket so we
+ ;; don't log twice.
+ (%make-void-port "w")
+ (current-output-port)))))
+
+ ;; Start the 'root' service.
+ (start root-service)
+
+ ;; This _must_ succeed. (We could also put the `catch' around
+ ;; `main', but it is often useful to get the backtrace, and
+ ;; `caught-error' does not do this yet.)
+ (catch #t
+ (lambda ()
+ (load-in-user-module (or config-file (default-config-file))))
+ (lambda (key . args)
+ (caught-error key args)
+ (quit 1)))
+ ;; Start what was started last time.
+ (and persistency
+ (catch 'system-error
+ (lambda ()
+ (start-in-order (read (open-input-file
+ persistency-state-file))))
+ (lambda (key . args)
+ (apply format #f (gettext (cadr args)) (caddr args))
+ (quit 1))))
+
+ (when (provided? 'threads)
+ ;; XXX: This terrible hack allows us to make sure that signal handlers
+ ;; get a chance to run in a timely fashion. Without it, after an EINTR,
+ ;; we could restart the accept(2) call below before the corresponding
+ ;; async has been queued. See the thread at
+ ;; <https://lists.gnu.org/archive/html/guile-devel/2013-07/msg00004.html>.
+ (sigaction SIGALRM (lambda _ (alarm 1)))
+ (alarm 1))
+
+ ;; Stop everything when we get SIGINT. When running as PID 1, that means
+ ;; rebooting; this is what happens when pressing ctrl-alt-del, see
+ ;; ctrlaltdel(8).
+ (sigaction SIGINT
+ (lambda _
+ (stop root-service)))
+
+ ;; Stop everything when we get SIGTERM.
+ (sigaction SIGTERM
+ (lambda _
+ (stop root-service)))
+
+ ;; Stop everything when we get SIGHUP.
+ (sigaction SIGHUP
+ (lambda _
+ (stop root-service)))
+
+ ;; Ignore SIGPIPE so that we don't die if a client closes the connection
+ ;; prematurely.
+ (sigaction SIGPIPE SIG_IGN)
+
+ (if (not socket-file)
+ ;; Get commands from the standard input port.
+ (process-textual-commands (current-input-port))
+ ;; Process the data arriving at a socket.
+ (let ((sock (open-server-socket socket-file))
+
+ ;; With Guile <= 2.0.9, we can get a system-error exception for
+ ;; EINTR, which happens anytime we receive a signal, such as
+ ;; SIGCHLD. Thus, wrap the 'accept' call.
+ (accept (EINTR-safe accept)))
+
+ ;; Possibly write out our PID, which means we're ready to accept
+ ;; connections. XXX: What if we daemonized already?
+ (match pid-file
+ ((? string? file)
+ (with-atomic-file-output pid-file
+ (cute display (getpid) <>)))
+ (#t (display (getpid)))
+ (_ #t))
+
+ (let next-command ()
+ (define (read-from sock)
+ (match (accept sock)
+ ((command-source . client-address)
+ (setvbuf command-source _IOFBF 1024)
+ (process-connection command-source))
+ (_ #f)))
+ (match (select (list sock) (list) (list) (if poll-services? 0.5 #f))
+ (((sock) _ _)
+ (read-from sock))
+ (_
+ #f))
+ (when poll-services?
+ (check-for-dead-services))
+ (next-command)))))))
(define (process-connection sock)
"Process client connection SOCK, reading and processing commands."
diff --git a/modules/shepherd/comm.scm b/modules/shepherd/comm.scm
index aeb138e..596a258 100644
--- a/modules/shepherd/comm.scm
+++ b/modules/shepherd/comm.scm
@@ -49,6 +49,7 @@
result->sexp
report-command-error
+ log-output-port
start-logging
stop-logging
make-shepherd-output-port
@@ -194,16 +195,18 @@ on service '~a':")
-;; Port for logging. This must always be a valid port, never `#f'.
-(define log-output-port (%make-void-port "w"))
-(define (start-logging file)
+(define log-output-port
+ ;; Port for logging. This must always be a valid port, never `#f'.
+ (make-parameter (%make-void-port "w")))
+
+(define (start-logging file) ;deprecated
(let ((directory (dirname file)))
(unless (file-exists? directory)
(mkdir directory)))
- (set! log-output-port (open-file file "al"))) ; line-buffered port
-(define (stop-logging)
- (close-port log-output-port)
- (set! log-output-port (%make-void-port "w")))
+ (log-output-port (open-file file "al")))
+(define (stop-logging) ;deprecated
+ (close-port (log-output-port))
+ (log-output-port (%make-void-port "w")))
(define %current-client-socket
;; Socket of the client currently talking to the daemon.
@@ -240,7 +243,7 @@ on service '~a':")
(if (not (string-index str #\newline))
(set! buffer (cons str buffer))
(let* ((log (lambda (x)
- (display x log-output-port)))
+ (display x (log-output-port))))
(init-line (lambda ()
(log (strftime (%current-logfile-date-format)
(localtime (current-time)))))))
diff --git a/modules/shepherd/support.scm b/modules/shepherd/support.scm
index 45a2030..380866e 100644
--- a/modules/shepherd/support.scm
+++ b/modules/shepherd/support.scm
@@ -23,7 +23,6 @@
(define-module (shepherd support)
#:use-module (shepherd config)
#:use-module (ice-9 match)
- #:use-module (ice-9 format)
#:export (call/ec
caught-error
assert
@@ -47,7 +46,7 @@
display-line
user-homedir
- default-logfile
+ user-default-log-file
default-logfile-date-format
default-config-file
default-socket-dir
@@ -308,19 +307,15 @@ TARGET should be a string representing a filepath + name."
""(for-each start '())
")))))
-;; Logfile.
-(define default-logfile
- (if (zero? (getuid))
- (if (access? "/dev/kmsg" W_OK)
- "/dev/kmsg"
- (string-append %localstatedir "/log/shepherd.log"))
- (string-append %user-config-dir "/shepherd.log")))
+;; Logging.
+(define (user-default-log-file)
+ "Return the file name of the user's default log file."
+ (mkdir-p %user-config-dir #o700)
+ (string-append %user-config-dir "/shepherd.log"))
(define default-logfile-date-format
;; 'strftime' format string to prefix each entry in the log.
- (if (string=? default-logfile "/dev/kmsg")
- (format #f "shepherd[~d]: " (getpid))
- "%Y-%m-%d %H:%M:%S "))
+ "%Y-%m-%d %H:%M:%S ")
;; Configuration file.
(define (default-config-file)
--
2.16.2
L
L
Ludovic Courtès wrote on 7 Mar 2018 12:04
[PATCH 3/3] Use syslog for logging when running as root.
(address . 30498@debbugs.gnu.org)
20180307110454.17110-4-ludo@gnu.org
* modules/shepherd/comm.scm (call-with-syslog-port, syslog-output-port):
New procedures.
* modules/shepherd.scm (main): Set 'log-output-port'
to (syslog-output-port) when running as root.
* doc/shepherd.texi (Invoking shepherd): Adjust accordingly.
---
doc/shepherd.texi | 18 ++++++++++---
modules/shepherd.scm | 2 +-
modules/shepherd/comm.scm | 66 +++++++++++++++++++++++++++++++++++++++++++++++
3 files changed, 81 insertions(+), 5 deletions(-)

Toggle diff (131 lines)
diff --git a/doc/shepherd.texi b/doc/shepherd.texi
index 01d8050..7946f8b 100644
--- a/doc/shepherd.texi
+++ b/doc/shepherd.texi
@@ -406,13 +406,23 @@ permissions are not as expected.
@cindex log file
Log output into @var{file}.
-The default behavior is to write to @file{/dev/kmsg} when running as
-superuser. This special device is GNU/Linux-specific; when it does not
-exist, write to @file{/var/log/shepherd.log} instead.
-
For unprivileged users, the default log file is
@file{$XDG_CONFIG_HOME/shepherd/shepherd.log}.
+@cindex syslog
+When running as root, the default behavior is to connect to
+@file{/dev/log}, the @dfn{syslog} socket (@pxref{Overview of Syslog,,,
+libc, The GNU C Library Reference Manual}). A syslog daemon,
+@command{syslogd}, is expected to read messages from there
+(@pxref{syslogd invocation, syslogd,, libc, GNU Inetutils}).
+
+When @file{/dev/log} is unavailable, for instance because
+@command{syslogd} is not running, as is the case during system startup
+and shutdown, @command{shepherd} falls back to the Linux kernel
+@dfn{ring buffer}, @file{/dev/kmsg}. If @file{/dev/kmsg} is missing, as
+is the case on other operating systems, it falls back to
+@file{/dev/console}.
+
@item --pid[=@var{file}]
When @command{shepherd} is ready to accept connections, write its PID to @var{file} or
to the standard output if @var{file} is omitted.
diff --git a/modules/shepherd.scm b/modules/shepherd.scm
index 39fbe14..fede338 100644
--- a/modules/shepherd.scm
+++ b/modules/shepherd.scm
@@ -168,7 +168,7 @@
(cond (logfile
(open-file logfile "al"))
((zero? (getuid))
- (open-file "/dev/kmsg" "wl"))
+ (syslog-output-port))
(else
(open-file (user-default-log-file) "al"))))
(%current-logfile-date-format
diff --git a/modules/shepherd/comm.scm b/modules/shepherd/comm.scm
index e686bfa..cbd8686 100644
--- a/modules/shepherd/comm.scm
+++ b/modules/shepherd/comm.scm
@@ -50,6 +50,7 @@
report-command-error
log-output-port
+ syslog-output-port
start-logging
stop-logging
make-shepherd-output-port
@@ -216,6 +217,71 @@ on service '~a':")
;; 'strftime' format strings for entries in the log file.
(make-parameter default-logfile-date-format))
+(define call-with-syslog-port
+ (let ((port #f)) ;connection to /dev/log
+ (lambda (proc)
+ "Call PROC with an open output port. The output port corresponds to
+/dev/log (aka. syslog) or, if that is unavailable, a degraded logging
+mechanism."
+ (define (call/syslog)
+ (catch 'system-error
+ (lambda ()
+ (proc port))
+ (lambda args
+ (if (memv (system-error-errno args)
+ (list ENOTCONN ECONNREFUSED EPIPE))
+ (begin
+ (set! port #f)
+ (call-with-syslog-port proc))
+ (apply throw args)))))
+
+ (or (and port (not (port-closed? port)) (call/syslog))
+ (let ((sock (socket AF_UNIX SOCK_DGRAM 0)))
+ (catch 'system-error
+ (lambda ()
+ (connect sock AF_UNIX "/dev/log")
+ (setvbuf sock _IOLBF)
+ (set! port sock)
+ (call/syslog))
+ (lambda args
+ (close-port sock)
+ (if (memv (system-error-errno args)
+ (list ENOENT ECONNREFUSED))
+ (catch 'system-error
+ (lambda ()
+ (call-with-output-file "/dev/kmsg"
+ (lambda (port)
+ (setvbuf port _IOFBF)
+ (proc port))))
+ (lambda args
+ (if (memv (system-error-errno args)
+ (list ENOENT EACCES EPERM))
+ (call-with-output-file "/dev/console"
+ (lambda (port)
+ (setvbuf port _IONBF)
+ (proc port)))
+ (apply throw args))))
+ (apply throw args)))))))))
+
+(define (syslog-output-port)
+ "Return the output port to write to syslog or /dev/kmsg, whichever is
+available."
+ (make-soft-port
+ (vector
+ (lambda (char) ;write char
+ (call-with-syslog-port
+ (lambda (port)
+ (write-char char port))))
+ (lambda (str) ;write string
+ (call-with-syslog-port
+ (lambda (port)
+ (display str port))))
+ (const #t) ;flush
+ #f ;get char
+ (lambda () ;close
+ (call-with-syslog-port close-port)))
+ "w")) ;output port
+
(define %not-newline
(char-set-complement (char-set #\newline)))
--
2.16.2
L
L
Ludovic Courtès wrote on 7 Mar 2018 13:46
Re: [bug#30498] [WIP v2 shepherd] shepherd: If /dev/kmsg is writable, use it for logging.
(name . Danny Milosavljevic)(address . dannym@scratchpost.org)(address . 30498@debbugs.gnu.org)
87po4gt5nl.fsf@gnu.org
Hello,

Danny Milosavljevic <dannym@scratchpost.org> skribis:

Toggle quote (8 lines)
>> There’s one thing we need to improve though: syslogd reads /proc/kmsg
>> and prefixes everything that comes from there with “vmunix” (as if it
>> came from the kernel).
>
> Also, apparently syslogd uses the timestamp of "when it read the messages
> out of /dev/kmsg" as syslog entry timestamp *although* /dev/kmsg contains its
> own timestamps (as offsets-from-bootup). Hrmmm...

Yeah, we could teach Inetutils’s syslogd to interpret those timestamps,
although that’s a Linux-specific thing so care must be taken.

Toggle quote (5 lines)
> According to the Linux kernel documentation the /dev/kmsg ring buffer is
> specifically allowed to be used by user processes (although they must not
> impersonate the kernel - if they try, the specified priority is ignored),
> so we're in the clear there.

Yeah but still. From syslogd’s viewpoint, you can only assume that
these messages originate in the kernel.

Toggle quote (8 lines)
> Later on, we should use /dev/log and fall back to /dev/kmsg and
> then again use /dev/log as it gets available etc. I'm not sure
> how to do the synchronisation (from shepherd's point of view,
> syslogd asynchronously reads from /dev/kmsg and puts the messages
> into its output files - so if we write to /dev/kmsg, then to
> /dev/log, then to /dev/kmsg, then to /dev/log, is the message order
> guaranteed?)

syslogd will read a batch of messages from /dev/kmsg when it starts, so
the order is not really honored in this case. I think that’s OK though,
because we don’t expect users to keep stopping/starting syslogd. :-)

Thanks,
Ludo’.
L
L
Ludovic Courtès wrote on 7 Mar 2018 16:25
Re: [PATCH 0/3] Log to syslog whenever possible
(address . 30498@debbugs.gnu.org)(name . Danny Milosavljevic)(address . dannym@scratchpost.org)
871sgvsyaf.fsf@gnu.org
Ludovic Courtès <ludo@gnu.org> skribis:

Toggle quote (4 lines)
> However! The downside is that messages upon shutdown written after
> syslogd has been killed are lost: they go to /dev/kmsg, which goes to
> the console at that point, but they’re not written anywhere.

I should point out that this is already the case in shepherd master.

Ludo’.
L
L
Ludovic Courtès wrote on 15 Mar 2018 18:00
Re: [bug#30498] [PATCH 0/3] Log to syslog whenever possible
(address . 30498-done@debbugs.gnu.org)(name . Danny Milosavljevic)(address . dannym@scratchpost.org)
87h8phtgtg.fsf@gnu.org
Ludovic Courtès <ludo@gnu.org> skribis:

Toggle quote (4 lines)
> Turn 'log-output-port' into a parameter.
> Simplify 'make-shepherd-output-port'.
> Use syslog for logging when running as root.

Pushed!

For the record, this can be tested on GuixSD by running “make dist” in
the Shepherd and then applying something like the patch below in Guix:
Toggle diff (31 lines)
diff --git a/gnu/packages/admin.scm b/gnu/packages/admin.scm
index ad31bc498..04cb69e1b 100644
--- a/gnu/packages/admin.scm
+++ b/gnu/packages/admin.scm
@@ -47,6 +47,7 @@
#:use-module (guix build-system perl)
#:use-module (guix build-system python)
#:use-module (guix build-system trivial)
+ #:use-module (guix gexp)
#:use-module (gnu packages)
#:use-module (gnu packages base)
#:use-module (gnu packages check)
@@ -159,16 +160,8 @@ and provides a \"top-like\" mode (monitoring).")
(define-public shepherd
(package
(name "shepherd")
- (version "0.3.2")
- (source (origin
- (method url-fetch)
- (uri (string-append "ftp://alpha.gnu.org/gnu/dmd/shepherd-"
- version ".tar.gz"))
- (sha256
- (base32
- "174q1qg7yg6w1hfvlfv720hr6hid4h5xzw15y3ycfpspllzldhcb"))
- (patches (search-patches "shepherd-close-fds.patch"
- "shepherd-herd-status-sorted.patch"))))
+ (version "0.3.3")
+ (source (local-file "/data/src/shepherd/shepherd-0.3.2.tar.gz"))
(build-system gnu-build-system)
(arguments
'(#:configure-flags '("--localstatedir=/var")))
Ludo’.
Closed
?
Your comment

This issue is archived.

To comment on this conversation send an email to 30498@debbugs.gnu.org

To respond to this issue using the mumi CLI, first switch to it
mumi current 30498
Then, you may apply the latest patchset in this issue (with sign off)
mumi am -- -s
Or, compose a reply to this issue
mumi compose
Or, send patches to this issue
mumi send-email *.patch