[sr-dev] [kamailio] kamailio 4.3 crash at run_trans_callbacks_internal (#322)

Thu Sep 10 11:29:43 CEST 2015

just caught another crash, cause there are lots of messages, I will waiting for your professional advise and get the right info you need.

#### Side Note

It reminds me a experience few days ago, I encounter several crash continuously in production servers and each crash on a different place.
After some test, I found it's due to new parameter `handle_lost_tcp` of `usrloc` module, without knowing the reason, it returns normal after I turn that parameter off. 

I not sure if this is related, but I also turn off it on staging server as well now.

```
modparam("usrloc", "close_expired_tcp", 0)
```

This time it generate 4 backtrace in a minute:

```
16:42 core.kamailio.sig11.115636.1441874475
16:42 core.kamailio.sig11.115603.1441874475
16:42 core.kamailio.sig11.115648.1441874504
16:43 core.kamailio.sig11.115576.1441874572
```

SYSLOG:

```
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: NOTICE: <script>: xx3 main route
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: DEBUG: tm [t_lookup.c:701]: t_lookupOriginalT(): DEBUG: t_lookupOriginalT: searching on hash entry 47045
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: DEBUG: tm [t_lookup.c:409]: matching_3261(): DEBUG: RFC3261 transaction matched, tid=.aDOUSxaqI
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: DEBUG: tm [t_lookup.c:798]: t_lookupOriginalT(): DEBUG: t_lookupOriginalT: canceled transaction found (0x7fb75dd823d8)!
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: DEBUG: tm [t_lookup.c:801]: t_lookupOriginalT(): DEBUG: t_lookupOriginalT completed
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: DEBUG: tm [tm.c:1043]: w_t_lookup_cancel(): lookup_original: t_lookupOriginalT returned: 0x7fb75dd823d8
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: INFO: <core> [mem/f_malloc.c:575]: fm_free(): freeing a free fragment (0x7fb75dd93cf0/0x7fb75dd93d28) - ignore
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: INFO: <core> [mem/f_malloc.c:575]: fm_free(): freeing a free fragment (0x7fb75dd83d88/0x7fb75dd83dc0) - ignore
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: INFO: <core> [mem/f_malloc.c:575]: fm_free(): freeing a free fragment (0x7fb75dd9ffa0/0x7fb75dd9ffd8) - ignore
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: DEBUG: dialog [dlg_handlers.c:302]: dlg_iuid_sfree(): freeing dlg iuid [0:0] (0x7fb75dd30065)
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: INFO: <core> [mem/f_malloc.c:575]: fm_free(): freeing a free fragment (0x7fb75dd3002d/0x7fb75dd30065) - ignore
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: INFO: <core> [mem/f_malloc.c:575]: fm_free(): freeing a free fragment (0x7fb75dd83d28/0x7fb75dd83d60) - ignore
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: INFO: <core> [mem/f_malloc.c:575]: fm_free(): freeing a free fragment (0x7fb75dd9b128/0x7fb75dd9b160) - ignore
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: INFO: <core> [mem/f_malloc.c:575]: fm_free(): freeing a free fragment (0x7fb75dd823a0/0x7fb75dd823d8) - ignore
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: NOTICE: <script>: ZZZZZZZZZZZZZZZZZZZZZZt_check_trans
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: NOTICE: <script>:  have see loose_route ?
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: DEBUG: <core> [parser/msg_parser.c:187]: get_hdr_field(): DEBUG: get_hdr_body : content_length=0
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: DEBUG: <core> [parser/msg_parser.c:89]: get_hdr_field(): found end of header
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: DEBUG: rr [loose.c:111]: find_first_route(): No Route headers found
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: DEBUG: rr [loose.c:927]: loose_route(): There is no Route HF
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: NOTICE: <script>: J get CANCEL protocol
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: NOTICE: <script>: [ROUTEDEBUG] enter route 1
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: NOTICE: <script>: XXY route 1
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: DEBUG: pv [pv_core.c:1110]: pv_get_dsturi(): no destination URI
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: DEBUG: pv [pv_core.c:1126]: pv_get_dsturi_attr(): no destination URI
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: DEBUG: pv [pv_core.c:1126]: pv_get_dsturi_attr(): no destination URI
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: DEBUG: pv [pv_core.c:1126]: pv_get_dsturi_attr(): no destination URI
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: DEBUG: pv [pv_core.c:386]: pv_get_xto_attr(): no Display name
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: DEBUG: pv [pv_core.c:353]: pv_get_contact(): no contact header!
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: DEBUG: registrar [regpv.c:178]: pv_get_ulc(): profile not set or no contacts there
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: NOTICE: <script>: avp route 1 rd=211.78.19.1 rp=5060 rm=CANCEL du=<null> dd=<null> ds=<null> dp=<null> oP=UDP dP=<null> td=211.78.19.1 rP=UDP #011#011#011XXsocket=<null> Xport=<null> ru{nameaddr.uri}=sip:0975074886 at 211.78.19.1 #011#011#011rU=0975074886 Ri=211.78.19.1 Rp=5003 fs=<null> si=118.163.134.250 sp=57562 fd=211.78.19.1 fn=<null> fu=sip:5777448 at 211.78.19.1 ru=sip:0975074886 at 211.78.19.1 ct=<null> #011#011#011sndto(ip)=<null> socket=<null> br=<null> bR=<null> DLG_status=<null>
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: DEBUG: tm [t_lookup.c:701]: t_lookupOriginalT(): DEBUG: t_lookupOriginalT: searching on hash entry 47045
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: DEBUG: tm [t_lookup.c:409]: matching_3261(): DEBUG: RFC3261 transaction matched, tid=.aDOUSxaqI
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: DEBUG: tm [t_lookup.c:798]: t_lookupOriginalT(): DEBUG: t_lookupOriginalT: canceled transaction found (0x7fb75dd823d8)!
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: DEBUG: tm [t_lookup.c:801]: t_lookupOriginalT(): DEBUG: t_lookupOriginalT completed
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: DEBUG: tm [t_lookup.c:1312]: t_newtran(): DEBUG: t_newtran: msg id=60 , global msg id=59 , T on entrance=0xffffffffffffffff
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: DEBUG: tm [t_lookup.c:466]: t_lookup_request(): t_lookup_request: start searching: hash=47045, isACK=0
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: DEBUG: tm [t_lookup.c:424]: matching_3261(): DEBUG: RFC3261 transaction matching failed
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: DEBUG: tm [t_lookup.c:648]: t_lookup_request(): DEBUG: t_lookup_request: no transaction found
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: DEBUG: tm [t_hooks.c:358]: run_reqin_callbacks_internal(): DBG: trans=0x7fb75dd99878, callback type 1, id 0 entered
Sep 10 16:41:15 sip1 /home/pkg/kamailio/sbin/kamailio[115636]: DEBUG: <core> [md5utils.c:67]: MD5StringArray(): MD5 calculated: a075ca4036a38176794f4f3679e1fbcd
Sep 10 16:41:15 sip1 kernel: [41700465.011740] kamailio[115636] general protection ip:7fb8dfae9a45 sp:7fffffa5ed28 error:0 in libc-2.13.so[7fb8df9c8000+182000]
Sep 10 16:41:15 sip1 kernel: [41700465.425038] kamailio[115603] general protection ip:601a63 sp:7fffffa62020 error:0 in kamailio[400000+3cb000]
```

---
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/322#issuecomment-139182962
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.sip-router.org/pipermail/sr-dev/attachments/20150910/3b223d03/attachment-0001.html>