[systemd-bugs] [Bug 69934] syslog()-calls just before a program exit are not be recorded in the journal

[bugzilla-daemon at freedesktop.org]

https://bugs.freedesktop.org/show_bug.cgi?id=69934

Zbigniew Jedrzejewski-Szmek <zbyszek at in.waw.pl> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|NEEDINFO                    |NEW

--- Comment #7 from Zbigniew Jedrzejewski-Szmek <zbyszek at in.waw.pl> ---
(In reply to comment #6)
> May you state which version of systemd you are using, which distro and the
> hardware you are running?
Kay's running systemd from git, and the hardware is the same, although it is
unlikely to be relevant.

> I guess it's a timing problem what I'm facing to. 
> Note the 'No such process' message in my trace output, I posted yesterday.
> It seems my application has gone too early for writing the output to the
> journal properly.
Yes. This means that the ancillary information like cgroup, commandline, etc.,
cannot be attached to the message. This is a known problem and doesn't explain
why the message gets lost.

> Or it might also be a configuration problen, but I did nothing special with
> systemd on my machine, just the installation defaults of Arch Linux.
> 
> Oh, I can reproduce the problem on two machines, both with Arch Linux
> installed:
> - A Lenovo X 1 with an Intel Core i5 with Arch 64Bits
> - An old Lenovo X 61 with an Intel Core 2 Duo with Arch 32Bits. 
Looking at the strace, journald gets to write_to_journal() correctly, and even
calls journal_file_append_entry(). I think so, because ftruncate() can be only
called from journal_file_post_change(), and journal_file_append_entry() is in
turn the only place where that can be called from. Normally
j_file_append_entry() would generate some fallocate calls:

open("/proc/28702/cgroup", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or
directory)
uname({sys="Linux", node="spora", ...}) = 0
fallocate(25, 0, 3817472, 4096)         = 0
fstat(25, {st_mode=S_IFREG|0640, st_size=3821568, ...}) = 0
mmap(NULL, 3821568, PROT_READ|PROT_WRITE, MAP_SHARED, 25, 0) = 0x7f271a1f6000
ftruncate(25, 3821568)                  = 0

In your strace, we go directly to ftruncate (which is used to tell listeners
that new data is available in the journal). I'm not sure what is going on here. 
I'll try to get arch installed and test if I can reproduce this, but it's going
to be at least a few days. It would be great if you could attach gdb to
journald, and set a breakpoint in write_to_journal() and see what happens
there.

> I hope this information help to find the problem.

-- 
You are receiving this mail because:
You are the QA Contact for the bug.
You are the assignee for the bug.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freedesktop.org/archives/systemd-bugs/attachments/20131001/079eb36d/attachment-0001.html>