[PATCH] Cache messaging dgm connections

Fri Sep 16 21:03:42 UTC 2016

On Fri, Sep 16, 2016 at 09:05:23AM -0700, Jeremy Allison wrote:
> On Fri, Sep 16, 2016 at 06:00:44PM +0200, Ralph Böhme wrote:
> > On Fri, Sep 16, 2016 at 08:36:33AM -0700, Jeremy Allison wrote:
> > > On Fri, Sep 16, 2016 at 11:29:06AM +0200, Ralph Böhme wrote:
> > > > On Thu, Sep 15, 2016 at 10:09:18AM -0700, Jeremy Allison wrote:
> > > > > On Thu, Sep 15, 2016 at 06:38:25PM +0200, Ralph Böhme wrote:
> > > > > > 
> > > > > > I got one through with these two patches. Running more...
> > > > > > 
> > > > > > Cheerio!
> > > > > 
> > > > > Oh, this looks more elegant than the reparent struct poll_funcs_tevent_context
> > > > > to ev patch I just posted...
> > > > > 
> > > > > The:
> > > > > 
> > > > >  +     TALLOC_FREE(msg->msg_dgm_ref);
> > > > > 
> > > > > looks very clever :-).
> > > > 
> > > > it passed three more autobuilds. Shall we push it?
> > > 
> > > Yes please - the version we discussed on the phone
> > > with the free of the timer events followed by context,
> > > plus the TALLOC_FREE(msg->msg_dgm_ref); change !
> > 
> > Then the attached is the one. Please push if ok.
> 
> 
> It's missing the:
> 
> +     size_t num_contexts = talloc_array_length(state->contexts);
> 
> in the second patch. With that added, pushed !

Still got the crash with this in autobuild, now with the backtrace
below. So we're still not catching everything (or something else
is freeing ev behind our backs :-).

As I know we're going to be co-located on Monday, let's
schedule a time to look at this directly at the SNIA
conf.

Cheers,

Jeremy.

#5  0x00002b5456a77a14 in sig_fault (sig=11) at ../lib/util/fault.c:94
No locals.
#6  <signal handler called>
No locals.
#7  0x00002b5460b9e960 in ?? ()
No symbol table info available.
#8  0x00002b5456b10a4b in tevent_debug (ev=0x2b5462179450, level=TEVENT_DEBUG_TRACE, fmt=0x2b5456b1b638 "Destroying timer event %p \"%s\"\n") at ../lib/tevent/tevent_debug.c:93
        ap = {{gp_offset = 24, fp_offset = 48, overflow_arg_area = 0x7ffc371c4ef0, reg_save_area = 0x7ffc371c4e30}}
#9  0x00002b5456b17a0d in tevent_common_timed_destructor (te=0x2b5460e90ef0) at ../lib/tevent/tevent_timed.c:140
No locals.
#10 0x00002b5456b47b5a in _tc_free_internal (tc=0x2b5460e90e90, location=0x2b54589b8f48 "../lib/poll_funcs/poll_funcs_tevent.c:670") at ../lib/talloc/talloc.c:1055
        d = 0x2b5456b179b7 <tevent_common_timed_destructor>
        ptr_to_free = 0x2b545dd40e00
        ptr = 0x2b5460e90ef0
#11 0x00002b5456b48ea1 in _tc_free_children_internal (tc=0x2b546970dd40, ptr=0x2b546970dda0, location=0x2b54589b8f48 "../lib/poll_funcs/poll_funcs_tevent.c:670") at ../lib/talloc/talloc.c:1570
        child = 0x2b5460e90ef0
        new_parent = 0x2b545a0f5120
#12 0x00002b5456b47d8b in _tc_free_internal (tc=0x2b546970dd40, location=0x2b54589b8f48 "../lib/poll_funcs/poll_funcs_tevent.c:670") at ../lib/talloc/talloc.c:1081
        ptr_to_free = 0x2b545dd40e00
        ptr = 0x2b546970dda0
#13 0x00002b5456b48ea1 in _tc_free_children_internal (tc=0x2b546556f4a0, ptr=0x2b546556f500, location=0x2b54589b8f48 "../lib/poll_funcs/poll_funcs_tevent.c:670") at ../lib/talloc/talloc.c:1570
        child = 0x2b546970dda0
        new_parent = 0x2b545a0f5120
#14 0x00002b5456b47d8b in _tc_free_internal (tc=0x2b546556f4a0, location=0x2b54589b8f48 "../lib/poll_funcs/poll_funcs_tevent.c:670") at ../lib/talloc/talloc.c:1081
        ptr_to_free = 0x2b545dd40e00
        ptr = 0x2b546556f500
#15 0x00002b5456b48005 in _talloc_free_internal (ptr=0x2b546556f500, location=0x2b54589b8f48 "../lib/poll_funcs/poll_funcs_tevent.c:670") at ../lib/talloc/talloc.c:1151
        tc = 0x2b546556f4a0
#16 0x00002b5456b492c0 in _talloc_free (ptr=0x2b546556f500, location=0x2b54589b8f48 "../lib/poll_funcs/poll_funcs_tevent.c:670") at ../lib/talloc/talloc.c:1693
        tc = 0x2b546556f4a0
#17 0x00002b54589b68c7 in poll_funcs_tevent_handle_destructor (handle=0x2b546987b400) at ../lib/poll_funcs/poll_funcs_tevent.c:670
No locals.
#18 0x00002b5456b47b5a in _tc_free_internal (tc=0x2b546987b3a0, location=0x2b54589b9690 "../source3/lib/messages_dgm_ref.c:140") at ../lib/talloc/talloc.c:1055
        d = 0x2b54589b6760 <poll_funcs_tevent_handle_destructor>
        ptr_to_free = 0x66
        ptr = 0x2b546987b400
#19 0x00002b5456b48005 in _talloc_free_internal (ptr=0x2b546987b400, location=0x2b54589b9690 "../source3/lib/messages_dgm_ref.c:140") at ../lib/talloc/talloc.c:1151
        tc = 0x2b546987b3a0
#20 0x00002b5456b492c0 in _talloc_free (ptr=0x2b546987b400, location=0x2b54589b9690 "../source3/lib/messages_dgm_ref.c:140") at ../lib/talloc/talloc.c:1693
        tc = 0x2b546987b3a0
#21 0x00002b54589b836f in msg_dgm_ref_destructor (r=0x2b5469928680) at ../source3/lib/messages_dgm_ref.c:140
        __func__ = "msg_dgm_ref_destructor"
#22 0x00002b5456b47b5a in _tc_free_internal (tc=0x2b5469928620, location=0x2b5456b97298 "../source4/lib/messaging/messaging.c:307") at ../lib/talloc/talloc.c:1055
        d = 0x2b54589b824e <msg_dgm_ref_destructor>
        ptr_to_free = 0x0
        ptr = 0x2b5469928680
#23 0x00002b5456b48005 in _talloc_free_internal (ptr=0x2b5469928680, location=0x2b5456b97298 "../source4/lib/messaging/messaging.c:307") at ../lib/talloc/talloc.c:1151
        tc = 0x2b5469928620
#24 0x00002b5456b492c0 in _talloc_free (ptr=0x2b5469928680, location=0x2b5456b97298 "../source4/lib/messaging/messaging.c:307") at ../lib/talloc/talloc.c:1693
        tc = 0x2b5469928620
#25 0x00002b5456b952f3 in imessaging_context_destructor (msg=0x2b54649f8d30) at ../source4/lib/messaging/messaging.c:307
No locals.
#26 0x00002b5456b47b5a in _tc_free_internal (tc=0x2b54649f8cd0, location=0x2b545dd8a8c0 "../source4/dsdb/samdb/ldb_modules/dns_notify.c:72") at ../lib/talloc/talloc.c:1055
        d = 0x2b5456b951e3 <imessaging_context_destructor>
        ptr_to_free = 0x2b5463675fe0
        ptr = 0x2b54649f8d30
#27 0x00002b5456b48ea1 in _tc_free_children_internal (tc=0x2b54613ccb50, ptr=0x2b54613ccbb0, location=0x2b545dd8a8c0 "../source4/dsdb/samdb/ldb_modules/dns_notify.c:72") at ../lib/talloc/talloc.c:1570
        child = 0x2b54649f8d30
        new_parent = 0x2b545a0f5120
#28 0x00002b5456b47d8b in _tc_free_internal (tc=0x2b54613ccb50, location=0x2b545dd8a8c0 "../source4/dsdb/samdb/ldb_modules/dns_notify.c:72") at ../lib/talloc/talloc.c:1081
        ptr_to_free = 0x2b545e7e3710
        ptr = 0x2b54613ccbb0
#29 0x00002b5456b48005 in _talloc_free_internal (ptr=0x2b54613ccbb0, location=0x2b545dd8a8c0 "../source4/dsdb/samdb/ldb_modules/dns_notify.c:72") at ../lib/talloc/talloc.c:1151
        tc = 0x2b54613ccb50
#30 0x00002b5456b492c0 in _talloc_free (ptr=0x2b54613ccbb0, location=0x2b545dd8a8c0 "../source4/dsdb/samdb/ldb_modules/dns_notify.c:72") at ../lib/talloc/talloc.c:1693
        tc = 0x2b54613ccb50
#31 0x00002b545dd86d44 in dns_notify_dnssrv_done (req=0x2b545e7e3790) at ../source4/dsdb/samdb/ldb_modules/dns_notify.c:72
        status = {v = 0}
        state = 0x2b54613ccbb0
        __FUNCTION__ = "dns_notify_dnssrv_done"
        __func__ = "dns_notify_dnssrv_done"
#32 0x00002b5456b12061 in _tevent_req_notify_callback (req=0x2b545e7e3790, location=0x2b5458373ec8 "default/source4/librpc/gen_ndr/ndr_irpc_c.c:1890") at ../lib/tevent/tevent_req.c:120
No locals.
#33 0x00002b5456b12134 in tevent_req_finish (req=0x2b545e7e3790, state=TEVENT_REQ_DONE, location=0x2b5458373ec8 "default/source4/librpc/gen_ndr/ndr_irpc_c.c:1890") at ../lib/tevent/tevent_req.c:157
No locals.
#34 0x00002b5456b1215b in _tevent_req_done (req=0x2b545e7e3790, location=0x2b5458373ec8 "default/source4/librpc/gen_ndr/ndr_irpc_c.c:1890") at ../lib/tevent/tevent_req.c:163
No locals.
#35 0x00002b5458369b8f in dcerpc_dnssrv_reload_dns_zones_r_done (subreq=0x0) at default/source4/librpc/gen_ndr/ndr_irpc_c.c:1890
        req = 0x2b545e7e3790
        status = {v = 0}
#36 0x00002b5456b12061 in _tevent_req_notify_callback (req=0x2b54612b2ca0, location=0x2b54583c6dc0 "../librpc/rpc/binding_handle.c:506") at ../lib/tevent/tevent_req.c:120
No locals.
#37 0x00002b5456b12134 in tevent_req_finish (req=0x2b54612b2ca0, state=TEVENT_REQ_DONE, location=0x2b54583c6dc0 "../librpc/rpc/binding_handle.c:506") at ../lib/tevent/tevent_req.c:157
No locals.
#38 0x00002b5456b1215b in _tevent_req_done (req=0x2b54612b2ca0, location=0x2b54583c6dc0 "../librpc/rpc/binding_handle.c:506") at ../lib/tevent/tevent_req.c:163
No locals.
#39 0x00002b54583c2598 in dcerpc_binding_handle_call_done (subreq=0x0) at ../librpc/rpc/binding_handle.c:506
        req = 0x2b54612b2ca0
        state = 0x2b54612b2e30
        h = 0x2b5463676040
        error = {v = 0}
        out_flags = 0
        ndr_err = NDR_ERR_SUCCESS
#40 0x00002b5456b12061 in _tevent_req_notify_callback (req=0x2b54616377a0, location=0x2b54583c69a8 "../librpc/rpc/binding_handle.c:187") at ../lib/tevent/tevent_req.c:120
No locals.
#41 0x00002b5456b12134 in tevent_req_finish (req=0x2b54616377a0, state=TEVENT_REQ_DONE, location=0x2b54583c69a8 "../librpc/rpc/binding_handle.c:187") at ../lib/tevent/tevent_req.c:157
No locals.
#42 0x00002b5456b1215b in _tevent_req_done (req=0x2b54616377a0, location=0x2b54583c69a8 "../librpc/rpc/binding_handle.c:187") at ../lib/tevent/tevent_req.c:163
No locals.
#43 0x00002b54583c1b28 in dcerpc_binding_handle_raw_call_done (subreq=0x0) at ../librpc/rpc/binding_handle.c:187
        req = 0x2b54616377a0
        state = 0x2b5461637930
        error = {v = 0}
#44 0x00002b5456b12061 in _tevent_req_notify_callback (req=0x2b546943f180, location=0x2b5456b979a0 "../source4/lib/messaging/messaging.c:971") at ../lib/tevent/tevent_req.c:120
No locals.
#45 0x00002b5456b12134 in tevent_req_finish (req=0x2b546943f180, state=TEVENT_REQ_DONE, location=0x2b5456b979a0 "../source4/lib/messaging/messaging.c:971") at ../lib/tevent/tevent_req.c:157
No locals.
#46 0x00002b5456b1215b in _tevent_req_done (req=0x2b546943f180, location=0x2b5456b979a0 "../source4/lib/messaging/messaging.c:971") at ../lib/tevent/tevent_req.c:163
No locals.
#47 0x00002b5456b96c48 in irpc_bh_raw_call_incoming_handler (irpc=0x2b546943f3b0, m=0x2b5464cbc0d0) at ../source4/lib/messaging/messaging.c:971
        req = 0x2b546943f180
        state = 0x2b546943f310
#48 0x00002b5456b95cb5 in irpc_handler_reply (msg_ctx=0x2b54649f8d30, m=0x2b5464cbc0d0) at ../source4/lib/messaging/messaging.c:535
        irpc = 0x2b546943f3b0
#49 0x00002b5456b96147 in irpc_handler (msg_ctx=0x2b54649f8d30, private_data=0x0, msg_type=1794, src=..., packet=0x7ffc371c5a80) at ../source4/lib/messaging/messaging.c:668
        m = 0x2b5464cbc0d0
        ndr_err = NDR_ERR_SUCCESS
#50 0x00002b5456b9597b in imessaging_dgm_recv (buf=0x2b54619e2078 "\005\324\t", buf_len=104, fds=0x7ffc371c5c70, num_fds=0, private_data=0x2b54649f8d30) at ../source4/lib/messaging/messaging.c:453
        d = 0x2b54614e1080
        next = 0x0
        msg = 0x2b54649f8d30
        msg_type = 1794
        src = {pid = 644105, task_id = 0, vnn = 4294967295, unique_id = 11843327406909580453}
        dst = {pid = 644101, task_id = 3381395428, vnn = 4294967295, unique_id = 9148323106942391271}
        srcbuf = {buf = "\350\372&ZT+\000\000\200Ý•aT+\000\000p", '\000' <repeats 15 times>, " \000\000\000\000\000\000\000@Û•aT+\000"}
        dstbuf = {buf = "`Û•aT+\000\000 Þ•aT+\000\000p\000\000\000\000\000\000\000`\356\310aT+\000\000`\356\310aT+\000\000\000\356\310aT+\000"}
        data = {data = 0x2b54619e20ac " \306p\347\006\v^K\215\207\242n \362\203@\001", length = 52}
        __FUNCTION__ = "imessaging_dgm_recv"
        __func__ = "imessaging_dgm_recv"
#51 0x00002b54589b823d in msg_dgm_ref_recv (msg=0x2b54619e2078 "\005\324\t", msg_len=104, fds=0x7ffc371c5c70, num_fds=0, private_data=0x0) at ../source3/lib/messages_dgm_ref.c:128
        r = 0x2b5469928680
        next = 0x2b545a117050
#52 0x00002b54589b7613 in messaging_dgm_recv (ctx=0x2b545a1bf5d0, msg=0x2b54619e2078 "\005\324\t", msg_len=104, fds=0x7ffc371c5c70, num_fds=0, private_data=0x2b5461c8ee60) at ../source3/lib/messages_dgm.c:340
        dgm_ctx = 0x2b5461c8ee60
#53 0x00002b54589b2d9f in unix_msg_recv (dgram_ctx=0x2b54611364b0, buf=0x2b54619e2078 "\005\324\t", buflen=104, fds=0x7ffc371c5c70, num_fds=0, private_data=0x2b545a1bf5d0) at ../source3/lib/unix_msg/unix_msg.c:1015
        ctx = 0x2b545a1bf5d0
        hdr = {msglen = 0, pid = 924606256, sock = 32764}
        msg = 0x0
        space = 140721233092400
        cookie = 0
#54 0x00002b54589b1626 in unix_dgram_recv_handler (w=0x2b54608c4000, fd=56, events=1, private_data=0x2b54611364b0) at ../source3/lib/unix_msg/unix_msg.c:334
        num_fds = 0
        fds = 0x7ffc371c5c70
        i = 0
        ctx = 0x2b54611364b0
        received = 112
        flags = 1073741824
        msg = {msg_name = 0x0, msg_namelen = 0, msg_iov = 0x7ffc371c5f20, msg_iovlen = 1, msg_control = 0x7ffc371c5c80, msg_controllen = 0, msg_flags = 1073741824}
        iov = {iov_base = 0x2b54619e2070, iov_len = 1024}
        bufsize = 528
        buf = 0x7ffc371c5c80 ""
#55 0x00002b54589b6577 in poll_funcs_fde_handler (ev=0x2b545a116dc0, fde=0x2b5460a468d0, flags=1, private_data=0x2b54608c4000) at ../lib/poll_funcs/poll_funcs_tevent.c:618
        w = 0x2b54608c4000
        events = 1
#56 0x00002b5456b19eaf in epoll_event_loop (epoll_ev=0x2b546104beb0, tvalp=0x7ffc371c6070) at ../lib/tevent/tevent_epoll.c:728
        fde = 0x2b5460a468d0
        flags = 1
        mpx_fde = 0x0
        ret = 1
        i = 0
        events = {{events = 1, data = {ptr = 0x2b5460a468d0, fd = 1621387472, u32 = 1621387472, u64 = 47641398634704}}}
        timeout = 250
        wait_errno = 0
#57 0x00002b5456b1a4e6 in epoll_event_loop_once (ev=0x2b545a116dc0, location=0x2b545a2007c8 "../source4/smbd/process_standard.c:364") at ../lib/tevent/tevent_epoll.c:930
        epoll_ev = 0x2b546104beb0
        tval = {tv_sec = 0, tv_usec = 249289}
        panic_triggered = false
#58 0x00002b5456b173a2 in std_event_loop_once (ev=0x2b545a116dc0, location=0x2b545a2007c8 "../source4/smbd/process_standard.c:364") at ../lib/tevent/tevent_standard.c:114
        glue_ptr = 0x2b545a116f00
        glue = 0x2b545a116f00
        ret = 0
#59 0x00002b5456b1033d in _tevent_loop_once (ev=0x2b545a116dc0, location=0x2b545a2007c8 "../source4/smbd/process_standard.c:364") at ../lib/tevent/tevent.c:680
        ret = 0
        nesting_stack_ptr = 0x0
#60 0x00002b5456b1064d in tevent_common_loop_wait (ev=0x2b545a116dc0, location=0x2b545a2007c8 "../source4/smbd/process_standard.c:364") at ../lib/tevent/tevent.c:803
        ret = 0
#61 0x00002b5456b17444 in std_event_loop_wait (ev=0x2b545a116dc0, location=0x2b545a2007c8 "../source4/smbd/process_standard.c:364") at ../lib/tevent/tevent_standard.c:145
        glue_ptr = 0x2b545a116f00
        glue = 0x2b545a116f00
        ret = -1
#62 0x00002b5456b106f0 in _tevent_loop_wait (ev=0x2b545a116dc0, location=0x2b545a2007c8 "../source4/smbd/process_standard.c:364") at ../lib/tevent/tevent.c:822
No locals.
#63 0x00002b545a1fffe7 in standard_new_task (ev=0x2b545a116dc0, lp_ctx=0x2b545a0f64a0, service_name=0x2b545dd3e35f "drepl", new_task=0x2b5456b3f5ae <task_server_callback>, private_data=0x2b545a11a520) at ../source4/smbd/process_standard.c:364
        pid = 644101
        state = 0x0
#64 0x00002b5456b3f748 in task_server_startup (event_ctx=0x2b545a116dc0, lp_ctx=0x2b545a0f64a0, service_name=0x2b545dd3e35f "drepl", model_ops=0x2b545a201b60 <standard_ops>, task_init=0x2b545dd2bce7 <dreplsrv_task_init>) at ../source4/smbd/service_task.c:114
        state = 0x2b545a11a520
#65 0x00002b5456b3db52 in server_service_init (name=0x2b545a0fa2c0 "drepl", event_context=0x2b545a116dc0, lp_ctx=0x2b545a0f64a0, model_ops=0x2b545a201b60 <standard_ops>) at ../source4/smbd/service.c:63
        srv = 0x2b545a116a60
#66 0x00002b5456b3dc95 in server_service_startup (event_ctx=0x2b545a116dc0, lp_ctx=0x2b545a0f64a0, model=0x2b545a0f57b0 "standard", server_services=0x2b545a0f9eb0) at ../source4/smbd/service.c:95
        status = {v = 0}
        i = 6
        model_ops = 0x2b545a201b60 <standard_ops>
        __FUNCTION__ = "server_service_startup"
#67 0x00002b54569e8e31 in binary_smbd_main (binary_name=0x2b54569e9711 "samba", argc=6, argv=0x7ffc371c66e8) at ../source4/smbd/server.c:489
        opt_daemon = false
        opt_interactive = true
        opt = -1
        pc = 0x2b545a0f51c0
        static_init = {0x2b5456b3d905 <server_service_auth_init>, 0x2b5456b40041 <server_service_echo_init>, 0x0}
        shared_init = 0x2b545a1427b0
        event_ctx = 0x2b545a116dc0
        stdin_event_flags = 1
        status = {v = 0}
        model = 0x2b545a0f57b0 "standard"
        max_runtime = 14400
        st = {st_dev = 8, st_ino = 56357436, st_nlink = 1, st_mode = 4480, st_uid = 1016, st_gid = 100, __pad0 = 0, st_rdev = 0, st_size = 0, st_blksize = 4096, st_blocks = 0, st_atim = {tv_sec = 1474043321, tv_nsec = 168391039}, st_mtim = {tv_sec = 1474043321, tv_nsec = 168391039}, st_ctim = {tv_sec = 1474043321, tv_nsec = 168391039}, __glibc_reserved = {0, 0, 0}}
        long_options = {{longName = 0x0, shortName = 0 '\000', argInfo = 4, arg = 0x2b5457414340 <poptHelpOptions>, val = 0, descrip = 0x2b54569e98d8 "Help options:", argDescrip = 0x0}, {longName = 0x2b54569e98e6 "daemon", shortName = 68 'D', argInfo = 0, arg = 0x0, val = 1000, descrip = 0x2b54569e98ed "Become a daemon (default)", argDescrip = 0x0}, {longName = 0x2b54569e9907 "interactive", shortName = 105 'i', argInfo = 0, arg = 0x0, val = 1001, descrip = 0x2b54569e9918 "Run interactive (not a daemon)", argDescrip = 0x0}, {longName = 0x2b54569e9937 "model", shortName = 77 'M', argInfo = 1, arg = 0x0, val = 1002, descrip = 0x2b54569e993d "Select process model", argDescrip = 0x2b54569e9952 "MODEL"}, {longName = 0x2b54569e9958 "maximum-runtime", shortName = 0 '\000', argInfo = 2, arg = 0x7ffc371c6340, val = 0, descrip = 0x2b54569e9968 "set maximum runtime of the server process, till autotermination", argDescrip = 0x2b54569e99a8 "seconds"}, {longName = 0x2b54569e99b0 "show-build", shortName = 98 'b', argInfo = 0, arg = 0x0, val = 1003, descrip = 0x2b54569e99bb "show build info", argDescrip = 0x0}, {longName = 0x0, shortName = 0 '\000', argInfo = 4, arg = 0x2b54569ec200 <popt_common_samba4>, val = 0, descrip = 0x2b54569e99cb "Common Samba options:", argDescrip = 0x0}, {longName = 0x0, shortName = 0 '\000', argInfo = 4, arg = 0x2b54569ec3c0 <popt_common_version4>, val = 0, descrip = 0x2b54569e99e1 "Version options:", argDescrip = 0x0}, {longName = 0x0, shortName = 0 '\000', argInfo = 0, arg = 0x0, val = 0, descrip = 0x0, argDescrip = 0x0}}
        __FUNCTION__ = "binary_smbd_main"
#68 0x00002b54569e8ed4 in main (argc=6, argv=0x7ffc371c66e8) at ../source4/smbd/server.c:512
No locals.