Milter-greylist

Seeing:

Jun 10 14:01:46 ureshii sm-mta[74920]: i5AI1kqX074920: Milter
(greylist): write(O) returned -1, expected 5: Broken pipe
Jun 10 14:01:46 ureshii sm-mta[74920]: i5AI1kqX074920: Milter
(greylist): to error state
Jun 10 14:01:46 ureshii sm-mta[74920]: i5AI1kqX074920: Milter
(greylist): init failed to open
Jun 10 14:01:46 ureshii sm-mta[74920]: i5AI1kqX074920: Milter
(greylist): to error state

milter-greylist will then need a restart.

Debugging options?

Graham

Graham Dunn <gdunn@...> wrote:

> Jun 10 14:01:46 ureshii sm-mta[74920]: i5AI1kqX074920: Milter
> (greylist): to error state
> 
> milter-greylist will then need a restart.
> 
> Debugging options?

Go to the build directory, do 
gdb ./milter-greylist
then use attach <pid> to attach the running milter-greylist.
then type bt

What do you have?

Other debugging: run in the foreground with options -Dv. What do you see
when it hangs?

-- 
Emmanuel Dreyfus
Il y a 10 sortes de personnes dans le monde: ceux qui comprennent 
le binaire et ceux qui ne le comprennent pas.
manu@...

On Thu, Jun 10, 2004 at 08:15:49PM +0200, Emmanuel Dreyfus wrote:
> Graham Dunn <gdunn@...> wrote:
> 
> > Jun 10 14:01:46 ureshii sm-mta[74920]: i5AI1kqX074920: Milter
> > (greylist): to error state
> > 
> > milter-greylist will then need a restart.
> > 
> > Debugging options?
> 
> Go to the build directory, do 
> gdb ./milter-greylist
> then use attach <pid> to attach the running milter-greylist.
> then type bt

ureshii# gdb milter-greylist
GNU gdb 4.18 (FreeBSD)
Copyright 1998 Free Software Foundation, Inc.
GDB is free software, covered by the GNU General Public License, and you
are
welcome to change it and/or distribute copies of it under certain
conditions.
Type "show copying" to see the conditions.
There is absolutely no warranty for GDB.  Type "show warranty" for
details.
This GDB was configured as "i386-unknown-freebsd"...Deprecated bfd_read
called at
/usr/src/gnu/usr.bin/binutils/gdb/../../../../contrib/gdb/gdb/dbxread.c
line 2627 in elfstab_build_psymtabs
Deprecated bfd_read called at
/usr/src/gnu/usr.bin/binutils/gdb/../../../../contrib/gdb/gdb/dbxread.c
line 933 in fill_symbuf

(gdb) attach 35668
Attaching to program:
/usr/home/gdunn/milter-greylist-1.3.9/milter-greylist, process 35668
Reading symbols from /usr/local/lib/libspf_alt.so.1...done.
Reading symbols from /usr/lib/libc_r.so.4...done.
Reading symbols from /usr/lib/libc.so.4...done.
Reading symbols from /usr/local/lib/libintl.so.6...done.
Reading symbols from /usr/local/lib/libiconv.so.3...done.
Reading symbols from /usr/libexec/ld-elf.so.1...done.
0x280e7934 in __sys_poll () from /usr/lib/libc_r.so.4
(gdb) bt
#0  0x280e7934 in __sys_poll () from /usr/lib/libc_r.so.4
#1  0x280e6e80 in _thread_kern_sched_state_unlock () from
/usr/lib/libc_r.so.4
#2  0x280e6845 in _thread_kern_scheduler () from /usr/lib/libc_r.so.4
#3  0x0 in ?? ()


Mean anything?

Graham

Graham Dunn <gdunn@...> wrote:

> #0  0x280e7934 in __sys_poll () from /usr/lib/libc_r.so.4
> #1  0x280e6e80 in _thread_kern_sched_state_unlock () from
> /usr/lib/libc_r.so.4
> #2  0x280e6845 in _thread_kern_scheduler () from /usr/lib/libc_r.so.4
> #3  0x0 in ?? ()
> 
> 
> Mean anything?

Not really. Use info threads, switch among them, and get the bt output
for each of them.

-- 
Emmanuel Dreyfus
Il y a 10 sortes de personnes dans le monde: ceux qui comprennent 
le binaire et ceux qui ne le comprennent pas.
manu@...

On Fri, Jun 11, 2004 at 10:02:08PM +0200, Emmanuel Dreyfus wrote:
> Graham Dunn <gdunn@...> wrote:
> 
> > #0  0x280e7934 in __sys_poll () from /usr/lib/libc_r.so.4
> > #1  0x280e6e80 in _thread_kern_sched_state_unlock () from
> > /usr/lib/libc_r.so.4
> > #2  0x280e6845 in _thread_kern_scheduler () from /usr/lib/libc_r.so.4
> > #3  0x0 in ?? ()
> > 
> > 
> > Mean anything?
> 
> Not really. Use info threads, switch among them, and get the bt output
> for each of them.

when this starts:

Jun 14 11:16:19 ureshii milter-greylist: greylist: accept() returned
invalid socket (Result too large), try again
Jun 14 11:16:19 ureshii sm-mta[67683]: i5EFGIpb067683: Milter
(greylist): write(O) returned -1, expected 5: Broken pipe
Jun 14 11:16:19 ureshii sm-mta[67683]: i5EFGIpb067683: Milter
(greylist): to err or state
Jun 14 11:16:19 ureshii sm-mta[67683]: i5EFGIpb067683: Milter
(greylist): init failed to open
Jun 14 11:16:19 ureshii sm-mta[67683]: i5EFGIpb067683: Milter
(greylist): to error state

gdb output:

(gdb) attach 58928
Attaching to program:
/usr/home/gdunn/milter-greylist-1.3.9/milter-greylist, process 58928
Reading symbols from /usr/local/lib/libspf_alt.so.1...done.
Reading symbols from /usr/lib/libc_r.so.4...done.
Reading symbols from /usr/lib/libc.so.4...done.
Reading symbols from /usr/local/lib/libintl.so.6...done.
Reading symbols from /usr/local/lib/libiconv.so.3...done.
Reading symbols from /usr/libexec/ld-elf.so.1...done.
0x280e7934 in __sys_poll () from /usr/lib/libc_r.so.4
(gdb) info threads
  9 process 58928, thread 9  0x280e6243 in _thread_kern_sched ()
   from /usr/lib/libc_r.so.4
  8 process 58928, thread 8  0x280e6243 in _thread_kern_sched ()
   from /usr/lib/libc_r.so.4
  7 process 58928, thread 7  0x280e6243 in _thread_kern_sched ()
   from /usr/lib/libc_r.so.4
  6 process 58928, thread 6  0x280e6243 in _thread_kern_sched ()
   from /usr/lib/libc_r.so.4
  5 process 58928, thread 5  0x280e6243 in _thread_kern_sched ()
   from /usr/lib/libc_r.so.4
  4 process 58928, thread 4  0x280e6243 in _thread_kern_sched ()
   from /usr/lib/libc_r.so.4
  3 process 58928, thread 3  0x280e6243 in _thread_kern_sched ()
   from /usr/lib/libc_r.so.4
  2 process 58928, thread 2  0x280e6243 in _thread_kern_sched ()
   from /usr/lib/libc_r.so.4
* 1 process 58928, thread 1  0x280e7934 in __sys_poll ()
   from /usr/lib/libc_r.so.4

(gdb) thread 1
[Switching to thread 1 (process 58928, thread 1)]
#0  0x280e7934 in __sys_poll () from /usr/lib/libc_r.so.4
(gdb) bt
#0  0x280e7934 in __sys_poll () from /usr/lib/libc_r.so.4
#1  0x280e6e80 in _thread_kern_sched_state_unlock () from
/usr/lib/libc_r.so.4
#2  0x280e6845 in _thread_kern_scheduler () from /usr/lib/libc_r.so.4
#3  0x0 in ?? ()
(gdb) thread 2
[Switching to thread 2 (process 58928, thread 2)]
#0  0x280e6243 in _thread_kern_sched () from /usr/lib/libc_r.so.4
(gdb) bt
#0  0x280e6243 in _thread_kern_sched () from /usr/lib/libc_r.so.4
#1  0x280e6a05 in _thread_kern_sched_state () from /usr/lib/libc_r.so.4
#2  0x280e3a5b in _select () from /usr/lib/libc_r.so.4
#3  0x280e3c4a in select () from /usr/lib/libc_r.so.4
#4  0x8054b6b in mi_rd_cmd ()
#5  0x8053cdc in mi_engine ()
#6  0x8052cd9 in mi_handle_session ()
#7  0x8052511 in mi_thread_handle_wrapper ()
#8  0x280aa128 in _thread_start () from /usr/lib/libc_r.so.4
#9  0xbf9ffffc in ?? ()
#10 0x80529ac in mi_listener ()
#11 0x8051d28 in smfi_main ()
#12 0x804aeed in main (argc=6, argv=0xbfbffbf4) at milter-greylist.c:801

(gdb) thread 3
[Switching to thread 3 (process 58928, thread 3)]
#0  0x280e6243 in _thread_kern_sched () from /usr/lib/libc_r.so.4
(gdb) bt
#0  0x280e6243 in _thread_kern_sched () from /usr/lib/libc_r.so.4
#1  0x280e6a05 in _thread_kern_sched_state () from /usr/lib/libc_r.so.4
#2  0x28103b1c in _recvfrom () from /usr/lib/libc_r.so.4
#3  0x28103bc2 in recvfrom () from /usr/lib/libc_r.so.4
#4  0x280eb3eb in res_send () from /usr/lib/libc_r.so.4
#5  0x280ee795 in res_query () from /usr/lib/libc_r.so.4
#6  0x28085998 in SPF_dns_lookup_resolv () from
/usr/local/lib/libspf_alt.so.1
#7  0x28082089 in SPF_dns_lookup () from /usr/local/lib/libspf_alt.so.1
#8  0x28084df7 in SPF_get_spf () from /usr/local/lib/libspf_alt.so.1
#9  0x2808446b in SPF_result () from /usr/local/lib/libspf_alt.so.1
#10 0x8051a26 in spf_alt_check (in=0x8086c80, 
    helo=0x8086ca4 "ahf211.neoplus.adsl.tpnet.pl", 
    fromp=0x80626e0 "<ywnr434ss@...>") at spf.c:177
#11 0x804a29d in mlfi_envfrom (ctx=0x8086c00, envfrom=0x8066160)
    at milter-greylist.c:229
#12 0x80545d7 in st_sender ()
#13 0x8053ecc in mi_engine ()
#14 0x8052cd9 in mi_handle_session ()
#15 0x8052511 in mi_thread_handle_wrapper ()
#16 0x280aa128 in _thread_start () from /usr/lib/libc_r.so.4
#17 0xbfaa9ffc in ?? ()
#18 0x80529ac in mi_listener ()
#19 0x8051d28 in smfi_main ()
#20 0x804aeed in main (argc=6, argv=0xbfbffbf4) at milter-greylist.c:801

(gdb) thread 4
[Switching to thread 4 (process 58928, thread 4)]
#0  0x280e6243 in _thread_kern_sched () from /usr/lib/libc_r.so.4
(gdb) bt
#0  0x280e6243 in _thread_kern_sched () from /usr/lib/libc_r.so.4
#1  0x280e6a05 in _thread_kern_sched_state () from /usr/lib/libc_r.so.4
#2  0x28103b1c in _recvfrom () from /usr/lib/libc_r.so.4
#3  0x28103bc2 in recvfrom () from /usr/lib/libc_r.so.4
#4  0x280eb3eb in res_send () from /usr/lib/libc_r.so.4
#5  0x280ee795 in res_query () from /usr/lib/libc_r.so.4
#6  0x28085998 in SPF_dns_lookup_resolv () from
/usr/local/lib/libspf_alt.so.1
#7  0x28082089 in SPF_dns_lookup () from /usr/local/lib/libspf_alt.so.1
#8  0x28084df7 in SPF_get_spf () from /usr/local/lib/libspf_alt.so.1
#9  0x2808446b in SPF_result () from /usr/local/lib/libspf_alt.so.1
#10 0x8051a26 in spf_alt_check (in=0x8086280, 
    helo=0x80862a4 "S01060004e204bbd0.vf.shawcable.", 
    fromp=0x8062560 "<Rhea@...>") at spf.c:177
#11 0x804a29d in mlfi_envfrom (ctx=0x8086080, envfrom=0x80660a0)
    at milter-greylist.c:229
#12 0x80545d7 in st_sender ()
#13 0x8053ecc in mi_engine ()
#14 0x8052cd9 in mi_handle_session ()
#15 0x8052511 in mi_thread_handle_wrapper ()
#16 0x280aa128 in _thread_start () from /usr/lib/libc_r.so.4
#17 0xbfa76ffc in ?? ()
#18 0x80529ac in mi_listener ()
#19 0x8051d28 in smfi_main ()
#20 0x804aeed in main (argc=6, argv=0xbfbffbf4) at milter-greylist.c:801

(gdb) thread 5
[Switching to thread 5 (process 58928, thread 5)]
#0  0x280e6243 in _thread_kern_sched () from /usr/lib/libc_r.so.4
(gdb) bt
#0  0x280e6243 in _thread_kern_sched () from /usr/lib/libc_r.so.4
#1  0x280e6a05 in _thread_kern_sched_state () from /usr/lib/libc_r.so.4
#2  0x28103b1c in _recvfrom () from /usr/lib/libc_r.so.4
#3  0x28103bc2 in recvfrom () from /usr/lib/libc_r.so.4
#4  0x280eb3eb in res_send () from /usr/lib/libc_r.so.4
#5  0x280ee795 in res_query () from /usr/lib/libc_r.so.4
#6  0x28085998 in SPF_dns_lookup_resolv () from
/usr/local/lib/libspf_alt.so.1
#7  0x28082089 in SPF_dns_lookup () from /usr/local/lib/libspf_alt.so.1
#8  0x28084df7 in SPF_get_spf () from /usr/local/lib/libspf_alt.so.1
#9  0x2808446b in SPF_result () from /usr/local/lib/libspf_alt.so.1
#10 0x8051a26 in spf_alt_check (in=0x8086900, 
    helo=0x8086924 "pcp01510572pcs.malvrn01.pa.comc", 
    fromp=0x8062420 "<OPGHFQNCHC@...>") at spf.c:177
#11 0x804a29d in mlfi_envfrom (ctx=0x8086780, envfrom=0x80660f0)
    at milter-greylist.c:229
#12 0x80545d7 in st_sender ()
#13 0x8053ecc in mi_engine ()
#14 0x8052cd9 in mi_handle_session ()
#15 0x8052511 in mi_thread_handle_wrapper ()
#16 0x280aa128 in _thread_start () from /usr/lib/libc_r.so.4
#17 0xbfabaffc in ?? ()
#18 0x80529ac in mi_listener ()
#19 0x8051d28 in smfi_main ()
#20 0x804aeed in main (argc=6, argv=0xbfbffbf4) at milter-greylist.c:801

(gdb) thread 6
[Switching to thread 6 (process 58928, thread 6)]
#0  0x280e6243 in _thread_kern_sched () from /usr/lib/libc_r.so.4
(gdb) bt
#0  0x280e6243 in _thread_kern_sched () from /usr/lib/libc_r.so.4
#1  0x280e6a05 in _thread_kern_sched_state () from /usr/lib/libc_r.so.4
#2  0x280a7cf0 in sigwait () from /usr/lib/libc_r.so.4
#3  0x8053563 in mi_signal_thread ()
#4  0x280aa128 in _thread_start () from /usr/lib/libc_r.so.4
#5  0x0 in ?? ()

(gdb) thread 7
[Switching to thread 7 (process 58928, thread 7)]
#0  0x280e6243 in _thread_kern_sched () from /usr/lib/libc_r.so.4
(gdb) bt
#0  0x280e6243 in _thread_kern_sched () from /usr/lib/libc_r.so.4
#1  0x280e6a72 in _thread_kern_sched_state_unlock () from
/usr/lib/libc_r.so.4
#2  0x280e86ed in pthread_cond_wait () from /usr/lib/libc_r.so.4
#3  0x804db79 in sync_sender (dontcare=0x0) at sync.c:865
#4  0x280aa128 in _thread_start () from /usr/lib/libc_r.so.4
#5  0x0 in ?? ()

(gdb) thread 8
[Switching to thread 8 (process 58928, thread 8)]
#0  0x280e6243 in _thread_kern_sched () from /usr/lib/libc_r.so.4
(gdb) bt
#0  0x280e6243 in _thread_kern_sched () from /usr/lib/libc_r.so.4
#1  0x280e6a72 in _thread_kern_sched_state_unlock () from
/usr/lib/libc_r.so.4
#2  0x280e894d in pthread_cond_timedwait () from /usr/lib/libc_r.so.4
#3  0x280d02a9 in _thread_gc () from /usr/lib/libc_r.so.4
#4  0x280aa128 in _thread_start () from /usr/lib/libc_r.so.4
#5  0x0 in ?? ()

(gdb) thread 9
[Switching to thread 9 (process 58928, thread 9)]
#0  0x280e6243 in _thread_kern_sched () from /usr/lib/libc_r.so.4
(gdb) bt
#0  0x280e6243 in _thread_kern_sched () from /usr/lib/libc_r.so.4
#1  0x280e6a05 in _thread_kern_sched_state () from /usr/lib/libc_r.so.4
#2  0x28103e60 in _nanosleep () from /usr/lib/libc_r.so.4
#3  0x280e110e in __sleep () from /usr/lib/libc_r.so.4
#4  0x280a7a71 in sleep () from /usr/lib/libc_r.so.4
#5  0x805147e in dumper (dontcare=0x0) at dump.c:138
#6  0x280aa128 in _thread_start () from /usr/lib/libc_r.so.4
#7  0x0 in ?? ()

> 
> -- 
> Emmanuel Dreyfus
> Il y a 10 sortes de personnes dans le monde: ceux qui comprennent 
> le binaire et ceux qui ne le comprennent pas.
> manu@...
> 
> 
> 
>  
> Yahoo! Groups Links
> 
> 
> 
>

Graham Dunn <gdunn@...> wrote:

Multiple threads are sleeping here:

> #3  0x28103bc2 in recvfrom () from /usr/lib/libc_r.so.4
> #4  0x280eb3eb in res_send () from /usr/lib/libc_r.so.4
> #5  0x280ee795 in res_query () from /usr/lib/libc_r.so.4
> #6  0x28085998 in SPF_dns_lookup_resolv () from
> /usr/local/lib/libspf_alt.so.1

I'd bet on a DNS resolver problem. If you build with BIND9, slibspf_alt
uses res_nquery instead of res_query, and we are sure DNS calls are
thread-safe.

Rebuild libspf_alt using --with-bind and supply the location of a BIND9
libbind.a. It should fix your problem.

-- 
Emmanuel Dreyfus
Il y a 10 sortes de personnes dans le monde: ceux qui comprennent 
le binaire et ceux qui ne le comprennent pas.
manu@...

On Mon, Jun 14, 2004 at 09:54:26PM +0200, Emmanuel Dreyfus wrote:
> Graham Dunn <gdunn@...> wrote:
> 
> Multiple threads are sleeping here:
> 
> > #3  0x28103bc2 in recvfrom () from /usr/lib/libc_r.so.4
> > #4  0x280eb3eb in res_send () from /usr/lib/libc_r.so.4
> > #5  0x280ee795 in res_query () from /usr/lib/libc_r.so.4
> > #6  0x28085998 in SPF_dns_lookup_resolv () from
> > /usr/local/lib/libspf_alt.so.1
> 
> I'd bet on a DNS resolver problem. If you build with BIND9, slibspf_alt
> uses res_nquery instead of res_query, and we are sure DNS calls are
> thread-safe.
> 
> Rebuild libspf_alt using --with-bind and supply the location of a BIND9
> libbind.a. It should fix your problem.

That seems to have fixed it. Bind 9.2.3 needs to be configured with the
--with-libbind argument in order to produce the correct libbind.a file
to compile libspf_alt against. 

Thanks,
Graham