Re: [systemd-devel] systemd hangs after Welcome message when LogLevel=debug

2014-01-20 Thread Barry Scott
On Fri 17 Jan 2014 21:17:04 Lennart Poettering wrote:
 On Tue, 14.01.14 13:31, Barry Scott (barry.sc...@onelan.co.uk) wrote:
  systemd-208-9.fc20.x86_64
  
  We have been porting a working configuration from fedora 19 to fedora 20.
  After systemd prints the Welcome message it then hangs.
 
 What do you mean by hangs? Is it just the output that doesn't continue
 anymore or does the entire system lock up?

After a few minutes nothing is output after the Welcome message.
No evidence that any unit start.

 
 Note that during really early boot the journal is not available yet,
 which means we can only log to kmsg then (and thus the
 console). However, as soon as the journal is available we then start
 logging directly to the journal. This might appear from the outside as
 if only during the first part of the boot output is generated if you
 only look at the console.

Understood and recall that I'm porting from F19 to F20 and this
works in F19.

With my engineer hat on I wonder why info messages can be output but not one 
debug message?

 You can use LogTarget=kmsg to redirect output to kmsg unconditionally,
 so that you get everything in kmsg and thus the console.

And by using the kernel option log_buf_len=128M we can make sure all the 
messages are kept.

Barry

___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/systemd-devel


Re: [systemd-devel] systemd hangs after Welcome message when LogLevel=debug

2014-01-20 Thread Lennart Poettering
On Fri, 17.01.14 16:52, David Timothy Strauss (da...@davidstrauss.net) wrote:

 It would be nice if bootup could realize the journal queue is full and
 wait for journal startup before proceeding further. It might cause
 some annoying non-determinism, though.

Not following here. Logging in syslog and the journal is synhchronous:
as soon as the socket fills up the clients start to block until the
other side made space again. THis means that no messages should be lost
and boot-up should be neatly synchronized to the logging sserver speed.

Note that by default the socket buffer is really small. The kernel puts
a limit to 15 messages by default, (/proc/sys/net/unix/max_dgram_qlen
can be used to change this, unfortunately only globally), and the socket
buffer limit in bytes is pretty short too... -- the latter is now bumped
if possible with systemd git, but that only works with priviliged
clients...

Lennart

-- 
Lennart Poettering, Red Hat
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/systemd-devel


Re: [systemd-devel] systemd hangs after Welcome message when LogLevel=debug

2014-01-20 Thread Lennart Poettering
On Mon, 20.01.14 11:22, Barry Scott (barry.sc...@onelan.co.uk) wrote:

 
 On Fri 17 Jan 2014 21:17:04 Lennart Poettering wrote:
  On Tue, 14.01.14 13:31, Barry Scott (barry.sc...@onelan.co.uk) wrote:
   systemd-208-9.fc20.x86_64
   
   We have been porting a working configuration from fedora 19 to fedora 20.
   After systemd prints the Welcome message it then hangs.
  
  What do you mean by hangs? Is it just the output that doesn't continue
  anymore or does the entire system lock up?
 
 After a few minutes nothing is output after the Welcome message.
 No evidence that any unit start.

It would be good to if I could have a look at the output of journalctl
-o short-monotonic -b of the log messages around the time where this
happens...

 With my engineer hat on I wonder why info messages can be output but not one 
 debug message?

Not following?

Lennart

-- 
Lennart Poettering, Red Hat
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/systemd-devel


Re: [systemd-devel] systemd hangs after Welcome message when LogLevel=debug

2014-01-20 Thread Barry Scott
On Mon 20 Jan 2014 13:21:14 Lennart Poettering wrote:
 On Mon, 20.01.14 11:22, Barry Scott (barry.sc...@onelan.co.uk) wrote:
  On Fri 17 Jan 2014 21:17:04 Lennart Poettering wrote:
   On Tue, 14.01.14 13:31, Barry Scott (barry.sc...@onelan.co.uk) wrote:
systemd-208-9.fc20.x86_64

We have been porting a working configuration from fedora 19 to fedora
20.
After systemd prints the Welcome message it then hangs.
   
   What do you mean by hangs? Is it just the output that doesn't continue
   anymore or does the entire system lock up?
  
  After a few minutes nothing is output after the Welcome message.
  No evidence that any unit start.
 
 It would be good to if I could have a look at the output of journalctl
 -o short-monotonic -b of the log messages around the time where this
 happens...

 
  With my engineer hat on I wonder why info messages can be output but not
  one debug message?
 
 Not following?

Given this problem has not trigger an insight from your selves I clearly
need to dig deeper to get more information.

I'm very busy at work at the moment but hope to come back to this to
help bottom out what is happening.

Barry

___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/systemd-devel


Re: [systemd-devel] systemd hangs after Welcome message when LogLevel=debug

2014-01-20 Thread Barry Scott
I drafted this last week, sorry for the delay.

On Wed 15 Jan 2014 16:44:21 Holger Schurig wrote:
 Educated guess (!)
 
 With LogLevel=debug, you generate huge amounts of output.

With LogTarget=syslog-or-kmsg and kernel not quiet I would expect to see the 
first few debug messages before it hung up. But nothing appears.

 With DefaultStandardOutput=syslog, you're asking systemd to send it's
 output to syslog.
 
 But while systemd is starting your system the syslog might not be
 ready. Probably systemd has some buffer, where it buffers the output.
 Once syslog becomes available, it will be fed with the buffer's
 contents first. If the output is small enought, as with LogLevel=info,
 this actually works. But when you generate gobs of output, the buffer
 will overflow and the output routine will wait until the buffer get's
 emptied, which it never will ...
 
 So, you might try to use DefaultStandardOutput=syslog-or-kmsg or
 DefaultStandardOutput=journal instead. The latter will eventually also
 send the output to syslog, which is why it's a default.

I guess you are saying that because all output must go to syslog and syslog is 
not running that systemd will hang. But why does the configuration work if 
LogLevel=info in that case?

Barry
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/systemd-devel


Re: [systemd-devel] systemd hangs after Welcome message when LogLevel=debug

2014-01-20 Thread Lennart Poettering
On Mon, 20.01.14 13:42, Barry Scott (barry.sc...@onelan.co.uk) wrote:

  But while systemd is starting your system the syslog might not be
  ready. Probably systemd has some buffer, where it buffers the output.
  Once syslog becomes available, it will be fed with the buffer's
  contents first. If the output is small enought, as with LogLevel=info,
  this actually works. But when you generate gobs of output, the buffer
  will overflow and the output routine will wait until the buffer get's
  emptied, which it never will ...
  
  So, you might try to use DefaultStandardOutput=syslog-or-kmsg or
  DefaultStandardOutput=journal instead. The latter will eventually also
  send the output to syslog, which is why it's a default.
 
 I guess you are saying that because all output must go to syslog and syslog 
 is 
 not running that systemd will hang. But why does the configuration work if 
 LogLevel=info in that case?

systemd will never hang on this. syslog-or-kmsg means that syslog is
used when it is up, and kmsg otherwise. We will not block on anything,
it's just a really simple condition check each time we write a msg.

Lennart

-- 
Lennart Poettering, Red Hat
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/systemd-devel


Re: [systemd-devel] systemd hangs after Welcome message when LogLevel=debug

2014-01-18 Thread Dominique Michel
Le Fri, 17 Jan 2014 16:52:44 -0800,
David Timothy Strauss da...@davidstrauss.net a écrit :

 It would be nice if bootup could realize the journal queue is full and
 wait for journal startup before proceeding further. It might cause
 some annoying non-determinism, though.
 
 We primarily see the problem with the logging from automounts and
 mount units.

In /etc/fstab, we can set if a partition must be mounted or not at
boot time, but not if, in the case it must be mounted, that partition is
vital for the system (i.e. / or /var) and the system must wait for it to
be mounted, or if that partition is not vital (i.e. /mnt/*) and the
system don't need to wait for it to boot. It would be great if such a
feature could be implemented in systemd or elsewhere.

Dominique
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/systemd-devel


Re: [systemd-devel] systemd hangs after Welcome message when LogLevel=debug

2014-01-18 Thread Tom Gundersen
On Sat, Jan 18, 2014 at 5:45 PM, Dominique Michel
dominique.mic...@vtxnet.ch wrote:
 Le Fri, 17 Jan 2014 16:52:44 -0800,
 David Timothy Strauss da...@davidstrauss.net a écrit :

 It would be nice if bootup could realize the journal queue is full and
 wait for journal startup before proceeding further. It might cause
 some annoying non-determinism, though.

 We primarily see the problem with the logging from automounts and
 mount units.

 In /etc/fstab, we can set if a partition must be mounted or not at
 boot time, but not if, in the case it must be mounted, that partition is
 vital for the system (i.e. / or /var) and the system must wait for it to
 be mounted, or if that partition is not vital (i.e. /mnt/*) and the
 system don't need to wait for it to boot. It would be great if such a
 feature could be implemented in systemd or elsewhere.

Isn't this precisely what 'fail'/'nofail' allows?

Cheers,

Tom
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/systemd-devel


Re: [systemd-devel] systemd hangs after Welcome message when LogLevel=debug

2014-01-18 Thread David Timothy Strauss
On Sat, Jan 18, 2014 at 8:45 AM, Dominique Michel
dominique.mic...@vtxnet.ch wrote:
 In /etc/fstab, we can set if a partition must be mounted or not at
 boot time, but not if, in the case it must be mounted, that partition is
 vital for the system (i.e. / or /var) and the system must wait for it to
 be mounted, or if that partition is not vital (i.e. /mnt/*) and the
 system don't need to wait for it to boot. It would be great if such a
 feature could be implemented in systemd or elsewhere.

We're using systemd automounts. Even if we weren't, auto-mounting on
first access isn't an fstab thing.
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/systemd-devel


Re: [systemd-devel] systemd hangs after Welcome message when LogLevel=debug

2014-01-17 Thread David Timothy Strauss
We're running into this too with lots of automount units. They log a
fair bit as they start, and that overwhelms the journal buffer before
it starts.
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/systemd-devel


Re: [systemd-devel] systemd hangs after Welcome message when LogLevel=debug

2014-01-17 Thread Lennart Poettering
On Tue, 14.01.14 13:31, Barry Scott (barry.sc...@onelan.co.uk) wrote:

 systemd-208-9.fc20.x86_64
 
 We have been porting a working configuration from fedora 19 to fedora 20.
 After systemd prints the Welcome message it then hangs.

What do you mean by hangs? Is it just the output that doesn't continue
anymore or does the entire system lock up?

Note that during really early boot the journal is not available yet,
which means we can only log to kmsg then (and thus the
console). However, as soon as the journal is available we then start
logging directly to the journal. This might appear from the outside as
if only during the first part of the boot output is generated if you
only look at the console.

You can use LogTarget=kmsg to redirect output to kmsg unconditionally,
so that you get everything in kmsg and thus the console.

Lennart

-- 
Lennart Poettering, Red Hat
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/systemd-devel


Re: [systemd-devel] systemd hangs after Welcome message when LogLevel=debug

2014-01-17 Thread David Timothy Strauss
On Fri, Jan 17, 2014 at 12:17 PM, Lennart Poettering
lenn...@poettering.net wrote:
 Note that during really early boot the journal is not available yet,
 which means we can only log to kmsg then (and thus the
 console). However, as soon as the journal is available we then start
 logging directly to the journal. This might appear from the outside as
 if only during the first part of the boot output is generated if you
 only look at the console.

The way we're seeing it manifest as freezes for 60 seconds a line in
bootup. After each 60 second timeout, we see a single line of kmsg
output, and then bootup continues until another item gets logged.

 You can use LogTarget=kmsg to redirect output to kmsg unconditionally,
 so that you get everything in kmsg and thus the console.

This seems to have major performance impacts versus logging to the journal.
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/systemd-devel


Re: [systemd-devel] systemd hangs after Welcome message when LogLevel=debug

2014-01-17 Thread David Timothy Strauss
It would be nice if bootup could realize the journal queue is full and
wait for journal startup before proceeding further. It might cause
some annoying non-determinism, though.

We primarily see the problem with the logging from automounts and mount units.
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/systemd-devel


Re: [systemd-devel] systemd hangs after Welcome message when LogLevel=debug

2014-01-15 Thread Holger Schurig
Educated guess (!)

With LogLevel=debug, you generate huge amounts of output.

With DefaultStandardOutput=syslog, you're asking systemd to send it's
output to syslog.

But while systemd is starting your system the syslog might not be
ready. Probably systemd has some buffer, where it buffers the output.
Once syslog becomes available, it will be fed with the buffer's
contents first. If the output is small enought, as with LogLevel=info,
this actually works. But when you generate gobs of output, the buffer
will overflow and the output routine will wait until the buffer get's
emptied, which it never will ...

So, you might try to use DefaultStandardOutput=syslog-or-kmsg or
DefaultStandardOutput=journal instead. The latter will eventually also
send the output to syslog, which is why it's a default.
___
systemd-devel mailing list
systemd-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/systemd-devel