autobuild: intermittent test failure detected

Thu Apr 28 09:00:33 MDT 2011

The autobuild test system has detected an intermittent failing test in 
the current master tree.

The autobuild log of the failure is available here:

   http://git.samba.org/autobuild.flakey/2011-04-28-1700/flakey.log

The samba3 build logs are available here:

   http://git.samba.org/autobuild.flakey/2011-04-28-1700/samba3.stderr
   http://git.samba.org/autobuild.flakey/2011-04-28-1700/samba3.stdout

The source4 build logs are available here:

   http://git.samba.org/autobuild.flakey/2011-04-28-1700/samba4.stderr
   http://git.samba.org/autobuild.flakey/2011-04-28-1700/samba4.stdout

The top commit at the time of the failure was:

commit 2e1522f3785d542c429fce83264ad67f35bcef68
Author: Volker Lendecke <vl at samba.org>
Date:   Wed Apr 27 17:52:30 2011 +0200

    s3: Close the winbind client fds after forking

    In an overload situation, the winbind helper child process inherits all those
    hundreds of fd's which it will never talk to. Close them.

    We (Christian Ambach and me) just saw a crash in libkrb5. Christian's analysis
    showed that libkrb5 also does select, probably exceeding FD_SETSIZE and
    crashing due to that reason. The parent winbind in theory does not do Kerberos
    at all, so this should fix that problem.

    The crash is interesting because the child process did not really crash.
    Somewhere in glibc backtrace() is called, probably due to an assert() or some
    explicit consistency check. This then somehow generates a signal probably due
    to corrupted memory structures. That signal triggers Samba to again call
    backtrace(). This blocks hard on a ptrace_once(). Sorry for the long backtrace
    here, but this *is* interesting.

    The child process blocking and not really crashing makes the situation worse:
    The parent process does not get told the child has crashed and more client
    sockets pile up.

    This patch is intended to put some relief on this problem by closing the
    majority of sockets the parent holds.

    (gdb) bt
    \#0  0x00002ad686a2b07b in pthread_once () from /lib64/libpthread.so.0
    \#1  0x00002ad6867adf87 in backtrace () from /lib64/libc.so.6
    \#2  0x00002ad683eab27c in log_stack_trace () at lib/util.c:1580
    \#3  0x00002ad683eab34b in smb_panic (why=0x2ad6841c6ec3 "internal error") at lib/util.c:1481
    \#4  0x00002ad683e9af3e in fault_report (sig=1) at lib/fault.c:52
    \#5  sig_fault (sig=1) at lib/fault.c:75 #6  <signal handler called>
    \#7  0x00002ad68673b005 in _int_malloc () from /lib64/libc.so.6
    \#8  0x00002ad68673c95d in calloc () from /lib64/libc.so.6
    \#9  0x00002ad684503e25 in _dl_new_object () from /lib64/ld-linux-x86-64.so.2
    \#10 0x00002ad6844ffadc in _dl_map_object_from_fd () from /lib64/ld-linux-x86-64.so.2
    \#11 0x00002ad684501d43 in _dl_map_object () from /lib64/ld-linux-x86-64.so.2
    \#12 0x00002ad68450ac8d in dl_open_worker () from /lib64/ld-linux-x86-64.so.2
    \#13 0x00002ad684506ed6 in _dl_catch_error () from /lib64/ld-linux-x86-64.so.2
    \#14 0x00002ad68450a68c in _dl_open () from /lib64/ld-linux-x86-64.so.2
    \#15 0x00002ad6867d0ba0 in do_dlopen () from /lib64/libc.so.6
    \#16 0x00002ad684506ed6 in _dl_catch_error () from /lib64/ld-linux-x86-64.so.2
    \#17 0x00002ad6867d0d07 in __libc_dlopen_mode () from /lib64/libc.so.6
    \#18 0x00002ad6867adeea in init () from /lib64/libc.so.6
    \#19 0x00002ad686a2b083 in pthread_once () from /lib64/libpthread.so.0
    \#20 0x00002ad6867adf87 in backtrace () from /lib64/libc.so.6
    \#21 0x00002ad68673285f in __libc_message () from /lib64/libc.so.6
    \#22 0x00002ad68673a30f in _int_free () from /lib64/libc.so.6
    \#23 0x00002ad68673a76b in free () from /lib64/libc.so.6
    \#24 0x00002ad6853fe346 in krb5int_sendto () from /usr/lib64/libkrb5.so.3
    \#25 0x00002ad6853fe511 in krb5_sendto_kdc () from /usr/lib64/libkrb5.so.3
    \#26 0x00002ad6853df7c4 in ?? () from /usr/lib64/libkrb5.so.3
    \#27 0x00002ad6853e0919 in krb5_get_init_creds () from /usr/lib64/libkrb5.so.3
    \#28 0x00002ad6853e2a94 in krb5_get_init_creds_password () from /usr/lib64/libkrb5.so.3
    \#29 0x00002ad684169ff1 in kerberos_kinit_password_ext (principal=0x2ad684702180 "<sanitized>", password=0x2ad6844c5bb0 "<sanitized>", time_offset=0, expire_time=0x2ad6846bf380, renew_till_time=0x0, cache_name=0x2ad6843cb3e0 "MEMORY:winbind_ccache", request_pac=false, add_netbios_addr=false, renewable_time=<value optimized out>, ntstatus=0x0) at libads/kerberos.c:223
    \#30 0x00002ad68416a223 in ads_kinit_password (ads=0x2ad6846bf330) at libads/kerberos.c:327
    \#31 0x00002ad68415f725 in ads_sasl_spnego_bind (ads=0x2ad6846bf330) at libads/sasl.c:812
    \#32 0x00002ad68415dbc1 in ads_sasl_bind (ads=0x2ad6846bf330) at libads/sasl.c:1114
    \#33 0x00002ad68415c09b in ads_connect (ads=0x2ad6846bf330) at libads/ldap.c:711
    \#34 0x00002ad683e1b8f7 in ads_cached_connection (domain=0x2ad6846b07c0) at winbindd/winbindd_ads.c:124
    \#35 0x00002ad683e1bc85 in sequence_number (domain=0x2ad6846b07c0, seq=0x2ad6846b0cd8) at winbindd/winbindd_ads.c:1233
    \#36 0x00002ad683dffdd7 in refresh_sequence_number (domain=0x2ad6846b07c0, force=128) at winbindd/winbindd_cache.c:510
    \#37 0x00002ad683e00520 in wcache_fetch (cache=<value optimized out>, domain=0x2ad6846b07c0, format=0x2ad68419901e "U/%s") at winbindd/winbindd_cache.c:638
    \#38 0x00002ad683e04ac8 in query_user (domain=0x2ad6846b07c0, mem_ctx=0x2ad6846bc920, user_sid=0x7fff1d0cb8c0, info=0x7fff1d0cb810) at winbindd/winbindd_cache.c:1910
    \#39 0x00002ad683df2d38 in winbindd_dual_userinfo (domain=0x2ad6846b07c0, state=0x7fff1d0cc9c0) at winbindd/winbindd_user.c:173
    \#40 0x00002ad683e232e0 in fork_domain_child (child=0x2ad6846c2440) at winbindd/winbindd_dual.c:485
    \#41 schedule_async_request (child=0x2ad6846c2440) at winbindd/winbindd_dual.c:319
    \#42 0x00002ad683e229f2 in async_request_fail (state=0x2ad6846c1d00) at winbindd/winbindd_dual.c:214
    \#43 0x00002ad683ebabec in run_events (ev=0x2ad6846aebf0, selrtn=0, read_fds=0x7fff1d0ce910, write_fds=<value optimized out>) at lib/events.c:123
    \#44 0x00002ad683df08cb in process_loop (argc=<value optimized out>, argv=<value optimized out>, envp=<value optimized out>) at winbindd/winbindd.c:1113
    \#45 main (argc=<value optimized out>, argv=<value optimized out>, envp=<value optimized out>) at winbindd/winbindd.c:1437

    Autobuild-User: Volker Lendecke <vlendec at samba.org>
    Autobuild-Date: Thu Apr 28 12:06:12 CEST 2011 on sn-devel-104