[systemd-devel] Journald stops logging when lots of output

[Pedro Francisco]

On Wed, Sep 11, 2013 at 7:35 PM, Lennart Poettering
<lennart at poettering.net> wrote:
> On Sat, 03.08.13 23:14, Pedro Francisco (pedrogfrancisco at gmail.com) wrote:
>
>> (question migrated from test at lists.fedoraproject.org )
>>
>> On Fedora 19, journald ( systemd-204-9.fc19.i686 ) stops logging. I
>> had enabled lots of iwl3945 debugging ( various messages for each
>> iwl3945 interaction -- modprobe iwl3945 debug=0x47ffffff ) throughout
>> the night and the last thing `journalctl -b` has is:
>>
>> Ago 03 02:25:45 s2 systemd-journal[29414]: Allowing system journal
>> files to grow to 1.4G.
>> Ago 03 02:25:45 s2 systemd-journal[29414]: Journal started
>> Ago 03 02:25:45 s2 systemd[1]: systemd-journald.service: main process
>> exited, code=exited, status=1/FAILURE
>> Ago 03 02:25:45 s2 systemd[1]: Started Trigger Flushing of Journal to
>> Persistent Storage.
>> Ago 03 02:25:45 s2 systemd[1]: systemd-journald.service: main process
>> exited, code=killed, status=10/USR1
>> Ago 03 02:25:45 s2 systemd[1]: Started Trigger Flushing of Journal to
>> Persistent Storage.
>> Ago 03 02:25:45 s2 systemd[1]: systemd-journald.service: main process
>> exited, code=killed, status=10/USR1
>> Ago 03 02:25:45 s2 systemd[1]: Started Trigger Flushing of Journal to
>> Persistent Storage.
>> Ago 03 02:25:45 s2 systemd-journal[29419]: Allowing system journal
>> files to grow to 1.4G.
>> Ago 03 02:25:45 s2 systemd-journal[29419]: Journal started
>> Ago 03 02:25:45 s2 systemd[1]: systemd-journald.service: main process
>> exited, code=exited, status=1/FAILURE
>> Ago 03 02:25:45 s2 systemd[1]: Started Trigger Flushing of Journal to
>> Persistent Storage.
>> Ago 03 02:25:45 s2 systemd-journal[29423]: Allowing system journal
>> files to grow to 1.4G.
>> Ago 03 02:25:45 s2 systemd-journal[29423]: Journal started
>> Ago 03 02:25:45 s2 systemd[1]: systemd-journald.service: main process
>> exited, code=exited, status=1/FAILURE
>> Ago 03 02:25:45 s2 systemd[1]: Started Trigger Flushing of Journal to
>> Persistent Storage.
>>
>> It is now 10:35 and while dmesg has (lots) of new info, journalctl -f does not.
>>
>> Any tips on what may be wrong?
>
> Is this still a problem?
>
> It seems journald dies for you for some reason. Is there a way how you
> can reproduce the issue? If so, can you strace the journal daemon, then
> reproduce it, and paste the last 100 strace lines somwhere before the
> daemon exited? This should give us an indication what might have failed
> that caused it to exit.
>
> (Of course, journald should not exit under any such circumstances, but
> to find that we first need to track down why it does that currently).

After rmmod iwl3945; modprobe iwl3945 debug=0x47ffffff :

$ sudo journalctl -f
-- Logs begin at Dom 2013-09-15 18:23:57 WEST. --
Set 17 23:49:10 s2 systemd-journal[2815]: Allowing system journal
files to grow to 1.4G.
Set 17 23:49:10 s2 systemd-journal[2815]: Journal started
Set 17 23:49:10 s2 NetworkManager[428]: <info> Config: set interface
ap_scan to 1
Set 17 23:49:10 s2 NetworkManager[428]: <info> (wlan0): supplicant
interface state: inactive -> scanning
Set 17 23:49:10 s2 systemd[1]: systemd-journald.service: main process
exited, code=exited, status=1/FAILURE
Set 17 23:49:10 s2 systemd[1]: Started Trigger Flushing of Journal to
Persistent Storage.
Set 17 23:49:11 s2 systemd-journal[2819]: Allowing system journal
files to grow to 1.4G.
Set 17 23:49:11 s2 systemd-journal[2819]: Journal started
Set 17 23:49:11 s2 systemd[1]: systemd-journald.service: main process
exited, code=exited, status=1/FAILURE
Set 17 23:49:11 s2 systemd[1]: Started Trigger Flushing of Journal to
Persistent Storage.

here systemd-journald process is no more.
# systemctl start systemd-journald
brings it back.

Attached is the contents of journald.log ( strace -p `pidof
systemd-journald` &> journald.log )

> Also, if you log using a tool like "logger", does that get lost too
> after the issue happens?

Haven't tried. Do you want me to?


Thank you for your time,
-- 
Pedro
-------------- next part --------------
A non-text attachment was scrubbed...
Name: journald-dies-20130918.log.gz
Type: application/x-gzip
Size: 39812 bytes
Desc: not available
URL: <http://lists.freedesktop.org/archives/systemd-devel/attachments/20130918/3dcaf435/attachment-0001.bin>