Klaus Schmidinger wrote:

Francois-Xavier KOWALSKI wrote:

...

Hello Klaus,

find below a tip upon Dominique's request.

...

Subject: [vdr] Process id in syslog From: Klaus Schmidinger Klaus.Schmidinger@cadsoft.de Date: Sat, 31 Dec 2005 15:12:24 +0100 To: vdr@linuxtv.org

To: vdr@linuxtv.org

Before the conversion to NPTL, the syslog entries showed the pid of each individual thread, so that it was easy to tell which thread had issued a particular message.

Now, with NPTL, all VDR syslog entries have the same pid, which is that of the foreground thread. This is pretty useless, because in case of a problem it's important to know exactly which thread has issued which message.

Since I couldn't find any information on this, maybe somebody here knows how openlog() needs to be called in order to have the individual thread pids displayed in syslog messages on an NPTL system.

Whatever pthread implementation is in use, the symlink /proc/self always refers to the LWPID (Light-Weight Process ID, i.e. thread PID in your case). I suggest -- this is what I do -- to stat(2) /proc/self refered file & sscanf(3) it. Of course, this is better to be done & stored (e.g. in TLS) at the thread startup & then re-used upon need.

Well, this isn't exactly what I meant. I do have the right pids in my program. What I want is that a call like

openlog("vdr", LOG_PID | LOG_CONS, LOG_USER);

followed by

syslog(LOG_INFO, "some log message");

writes to the log file

Jan 7 12:25:52 video vdr[7457]: some log message

where [7457] should be the pid of the actual thread, not that of the main thread.

For instance, on a non-NPTL system, the log looks like this:

Dec 10 14:38:51 video vdr[709]: VDR version 1.3.38 started Dec 10 14:38:51 video vdr[709]: loading /video/setup.conf ... Dec 10 14:38:51 video vdr[711]: video directory scanner thread started (pid=711, tid=711)

while on an NPTL system I get:

Jan 7 12:25:51 video vdr[7457]: VDR version 1.3.38 started Jan 7 12:25:51 video vdr[7457]: loading /video/setup.conf ... Jan 7 12:25:52 video vdr[7457]: video directory scanner thread started (pid=7457, tid=7459)

As you can see, in the first case there is vdr[709] for the main thread and vdr[711] for the second thread. In the second case there is vdr[7457] for both threads, while I would like the second thread to show vdr[7459].

Here's a manually created example of how this should look:

Jan 7 12:25:51 video vdr[7457]: VDR version 1.3.38 started Jan 7 12:25:51 video vdr[7457]: loading /video/setup.conf ... Jan 7 12:25:52 video vdr[7459]: video directory scanner thread started (pid=7457, tid=7459)

Hi Klaus,

a short look into the documentation gave me the impression, that your wish is not yet supported by the glibc, at least on my Debian Sarge system. An idea might be to check, what happens if you do the openlog call for testing in the desired thread, e.g. for testing before every syslog call. If this does not produce to much load and solves the problem, I would say "Just do it!" and post a according bug report to the glibc-Developers. :-)

Just my 2 cents,

[No sent to the ML as my previous message was refused because I am not a subscriber]

Klaus Schmidinger wrote:

Francois-Xavier KOWALSKI wrote:

...

...

Subject: [vdr] Process id in syslog From: Klaus Schmidinger Klaus.Schmidinger@cadsoft.de Date: Sat, 31 Dec 2005 15:12:24 +0100 To: vdr@linuxtv.org

To: vdr@linuxtv.org

Before the conversion to NPTL, the syslog entries showed the pid of each individual thread, so that it was easy to tell which thread had issued a particular message.

Now, with NPTL, all VDR syslog entries have the same pid, which is that of the foreground thread. This is pretty useless, because in case of a problem it's important to know exactly which thread has issued which message.

Since I couldn't find any information on this, maybe somebody here knows how openlog() needs to be called in order to have the individual thread pids displayed in syslog messages on an NPTL system.

Whatever pthread implementation is in use, the symlink /proc/self always refers to the LWPID (Light-Weight Process ID, i.e. thread PID in your case). I suggest -- this is what I do -- to stat(2) /proc/self refered file & sscanf(3) it. Of course, this is better to be done & stored (e.g. in TLS) at the thread startup & then re-used upon need.

Well, this isn't exactly what I meant. I do have the right pids in my program. What I want is that a call like

openlog("vdr", LOG_PID | LOG_CONS, LOG_USER);

followed by

syslog(LOG_INFO, "some log message");

writes to the log file

Jan 7 12:25:52 video vdr[7457]: some log message

where [7457] should be the pid of the actual thread, not that of the main thread.

For instance, on a non-NPTL system, the log looks like this:

Dec 10 14:38:51 video vdr[709]: VDR version 1.3.38 started Dec 10 14:38:51 video vdr[709]: loading /video/setup.conf ... Dec 10 14:38:51 video vdr[711]: video directory scanner thread started (pid=711, tid=711)

while on an NPTL system I get:

Jan 7 12:25:51 video vdr[7457]: VDR version 1.3.38 started Jan 7 12:25:51 video vdr[7457]: loading /video/setup.conf ... Jan 7 12:25:52 video vdr[7457]: video directory scanner thread started (pid=7457, tid=7459)

As you can see, in the first case there is vdr[709] for the main thread and vdr[711] for the second thread. In the second case there is vdr[7457] for both threads, while I would like the second thread to show vdr[7459].

Hmm I see. This was a non-UNIX Linux-ism of LinuxThreads. NPTL folks now have "fixed" it. What I could suggest you is to use the UNIX approach (that would be portable), i.e. not assume that both processes & threads are both LWP's & hence have distinct LWPID's: use pthread_t (that maps nicely to a long on most UNIX platforms) reported by pthread_self() in addition to PID. Then overload/redefine openlog/syslog.

Something like the following (untested) should do the job with a reasonable CPU budget. Note that the thread is between curlybraces at the beginning of each line.

static void _vdr_get_fmt(void) { static char* __thread vdr_log_prefix = NULL; /* in TLS */ static char* __thread vdr_log_fmt = NULL; /* in TLS */ if( !vdr_log_prefix) { vdr_log_prefix = (char*)malloc(16); sprintf(vdr_log_prefix, "{%ld} ", (long)pthread_self() ); } if( !vdr_log_fmt) vdr_log_fmt = (char*)malloc(1024); strcpy( vdr_log_fmt, vdr_log_prefix ); return vdr_log_fmt; }

void vdr_syslog(int priority, const char *format, ...){ va_list ap; char* fmt = _vdr_get_fmt(); va_start( ap, format ); strcat( fmt, format ); vsyslog( priority, fmt, ap ); va_end(ap); }

Good luck.