[SOLVED] Problems with systemd's journal when using syslog() in C

thesofty · 2013-09-28 13:58:40

Hi,

I have a problem with journalctl and syslog output within a C program:

When I use journalctl in follow mode:
$ journalctl -f

and I run the folowing program in another terminal

#include <stdio.h>
#include <syslog.h>

int main()
{
    FILE *pf;
    int i;
	
    /* logging made in file /var/log/syslog */ 
    openlog("martins",LOG_CONS,LOG_USER);
	
    pf = fopen("not_here","r");
    if (!pf)
        syslog(LOG_ERR | LOG_USER,"oops -- %m\n");

	return 0;
}

no syslog error message appears in the journal.

But, when I modify the programm by adding a 'sleep(1);' right before 'return 0;'
there is a correct error message shown in the journal.

Is this a bug in systemd? Or do I understand something wrong with systemd's journal?

I'm actually running
linux-3.10-12-1-lts
systemd 207

with a 32Bit installation

Thanks for any hints,

Martin

Last edited by thesofty (2013-10-01 19:10:13)

zorro · 2013-09-29 14:06:53

You may need to call closelog() for correct operation.

thesofty · 2013-09-29 17:50:41

Nope, I tried it out. It didn't help.
It's just the same. With some artificial delay, the message appears in the journal DB. Without, no message will arrive the journal DB, even if closelog() is called before.

Meanwhile I could reproduce this behavior on 64Bit system too.

The delay needs not to be a sleep(), an incrementing loop does the same job when the counting limit is high enough.
On my system, a
for (i=0;i<1000000;i++) ;
before the exit() works.
But a limit of 100000 instead of 1000000 is not sufficient.

thesofty · 2013-09-29 18:52:00

Meanwhile I'm pretty sure that's a serious bug. Serious, because the user will not see the reasons when services terminate on his system because of some error conditions. Hence, I've file a bug ticket to freedesktop.org.
https://bugs.freedesktop.org/show_bug.cgi?id=69934

thesofty · 2013-10-01 19:04:17

Now, I understand what's going on:

1) There is an known issue about a race condition in journald when the logging process exits. In this case the message isn't assigned to the user whose process generated the message.

2) Apparently the group of the journal files have been changed from 'adm' to 'systemd-journal' in Arch Linux around April 2013.
But still I only have been member of 'adm' as described in the journal tutorial on http://0pointer.de/blog/projects/journalctl.html. So I can only see syslog messages, which are correctly assigned to my own user account. The messages with the race condition, as mentioned above, have been invisible to me.

After joining to the new right group again:
$ sudo usermod -d G martin systemd-journal

I also see the syslog messaes just before exiting the process again :-).

Arch Linux

#1 2013-09-28 13:58:40

[SOLVED] Problems with systemd's journal when using syslog() in C

#2 2013-09-29 14:06:53

Re: [SOLVED] Problems with systemd's journal when using syslog() in C

#3 2013-09-29 17:50:41

Re: [SOLVED] Problems with systemd's journal when using syslog() in C

#4 2013-09-29 18:52:00

Re: [SOLVED] Problems with systemd's journal when using syslog() in C

#5 2013-10-01 19:04:17

Re: [SOLVED] Problems with systemd's journal when using syslog() in C

Board footer