lkml.org 
[lkml]   [1999]   [Feb]   [2]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
Date
From
SubjectRe: linux syslog problems (now linux-2.2.1+glibc-2.0.112)
[Zack Weinberg]
> Please do `strace -p 1117' which will reveal the system call
> arguments. While strace is still running, send process 1117 a
> non-lethal signal (SIGHUP probably works) - that will hopefully
> cause the send() to return EINTR. Then watch the system call trace
> until it gets stuck again, loops, or exits, and send us the output.

Doing a strace got me this (just leaving it run until it croaked):

time([917975878]) = 917975878
recvfrom(7, "\1\1\6\1\262\334sF\0\1\0\0\0\0\0"..., 1540, 0, {sin_family=AF_INET, sin_port=htons(68), sin_addr=inet_addr("132.241.200.1")}, [16]) = 548
read(8, "\0`\227\337I\25\0`/q\372@\10\0E\0"..., 1500) = 590
time([917975878]) = 917975878
SYS_174(0xd, 0xbfffdfd0, 0xbfffdf44, 0x8, 0xd) = 0
send(3, "<30>Feb 2 09:17:58 dhcpd: DHCPR"..., 100, 0) = 100
SYS_174(0xd, 0xbfffdfd0, 0, 0x8, 0xd) = 0
time([917975878]) = 917975878
SYS_174(0xd, 0xbffff2b4, 0xbffff228, 0x8, 0xd) = 0
send(3, "<30>Feb 2 09:17:58 dhcpd: DHCPO"..., 93, 0 <unfinished ...>

Can't strace and gdb at the same time, so I killed strace and ran
gdb. This is dhcpd-2.0b1pl8 staticly linked against glibc-2.0.112 now:

#0 0x806d212 in __libc_send ()
#1 0x806cc08 in vsyslog (pri=6, fmt=0x9 <Address 0x9 out of bounds>,
ap=0xbffff548) at syslog.c:209
#2 0x806c8fd in syslog (pri=6,
fmt=0x80e01a0 "DHCPOFFER on 132.241.11.34 to 00:05:02:3e:96:5f via 132.241.200.1") at syslog.c:106
#3 0x8059119 in note (fmt=0x80be8d4 "%s on %s to %s via %s") at errwarn.c:133
#4 0x804bab0 in dhcp_reply (lease=0x81b24a8) at dhcp.c:1114
#5 0x80489e3 in lease_ping_timeout (vlp=0x81b24a8) at dhcpd.c:344
#6 0x8051bce in dispatch () at dispatch.c:643
#7 0x804887e in main (argc=1, argv=0xbffffdb4, envp=0xbffffdbc) at dhcpd.c:279
#8 0x805a4a3 in __libc_start_main (main=0x8048190 <main>, argc=1,
argv=0xbffffdb4, init=0x80480b4 <_init>, fini=0x80be220 <_fini>,
rtld_fini=0, stack_end=0xbffffdac) at ../sysdeps/generic/libc-start.c:78

Grr. Forgot to grab my new version of strace! It bails when I
SIGPIPE it:

send(3, "<30>Feb 2 09:17:58 dhcpd: DHCPO"..., 93, 0) = ? ERESTARTSYS (To be restarted)
--- SIGPIPE (Broken pipe) ---
close(3) = 0
sigreturn(Segmentation fault

Now, at this point, strace and gdb aren't showing anything. With
strace showing no activity and gdb not falling through to a prompt,
I don't know what that means. I probably botched it at this point and
unstuck it enough that an extra SIGPIPE killed it (having fallen though
glibc's syslog() eventually).

> Incidentally, debug info is substantially smaller if you use -ggdb
> instead of plain -g.

Smaller, but not tiny. Enough to fit though...


> This might be a bug in strace or it might be the kernel returning
> something totally unexpected. Probably the first. Ulrich has an
> updated strace somewhere, check ftp.cygnus.com.

I grabbed strace-3.1ud-b9 off of cygnus. I forgot to use it when
I did the above strace, but I put it on that computer for next time.
I had to patch it to get it to compile (see patch). I was guessing
at the EXEC_vfork/SYS_vfork bit, but it seems to be doing what it is
supposed to be doing.

> Then the bug is unlikely to be in syslogd, unless the pipe has
> gotten lost from syslogd's select() fdset. You ought to be able
> to check that with lsof and strace.

Joy. I'll crunch up lsof and stare at it.


For extra ammo, up till now the linux-2.2.1 kernel was compiled with
gcc-2.7.2.3. I also tried egcs-1.1.1 with the same results.
--- john

-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.rutgers.edu
Please read the FAQ at http://www.tux.org/lkml/

\
 
 \ /
  Last update: 2005-03-22 13:50    [W:0.030 / U:0.688 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site