[sr-dev] [kamailio/kamailio] q_malloc crash on Kamailio 5.2.3 with http_async_query function (#2091)
Michal Škuta
notifications at github.com
Mon Oct 7 15:54:02 CEST 2019
Hi, Kamailio always crashes on the function http_async_query. We are using a lot of functions from the evapi module in this version of Kamailio. Do not know if this can be a problem.
Tried to increase debug level: the most important parts:
` 1(17805) INFO: <script>: XLOG: 507c05c9-f94b-416f-b7a5-40082058db66 [dialog:end] Dialog ended 1(17805) DEBUG: tm [t_lookup.c:1346]: t_newtran(): msg (0x97a9a5d4) id=52/17805 global id=48/17805 T start=0xffffffff
1(17805) DEBUG: tm [t_lookup.c:500]: t_lookup_request(): start searching: hash=28167, isACK=0
1(17805) DEBUG: tm [t_lookup.c:458]: matching_3261(): RFC3261 transaction matching failed - via branch [z9hG4bK70e6.42d96d25af99afef172241e1e9547b60.1]
1(17805) DEBUG: tm [t_lookup.c:682]: t_lookup_request(): no transaction found
1(17805) DEBUG: tm [t_hooks.c:349]: run_reqin_callbacks_internal(): trans=0x568003ec, callback type 1, id 0 entered
1(17805) DEBUG: tm [t_hooks.c:349]: run_reqin_callbacks_internal(): trans=0x568003ec, callback type 1, id 0 entered
1(17805) DEBUG: <core> [core/md5utils.c:67]: MD5StringArray(): MD5 calculated: 590cbe8fad9cc87ce2e04cda6be5294b
1(17805) DEBUG: http_async_client [async_http.c:472]: async_send_query(): transaction suspended [28167:1741767803]
1(17805) DEBUG: http_async_client [async_http.c:625]: async_push_query(): query sent [http://192.168.6.23:2080/cdr_http] (0x567fe4a0) to worker 1
1(17805) DEBUG: dialog [dlg_hash.c:712]: dlg_lookup(): ref dlg 0x567f52e0 with 1 -> 5
1(17805) DEBUG: dialog [dlg_hash.c:714]: dlg_lookup(): dialog id=8549 found on entry 3536
1(17805) DEBUG: dialog [dlg_hash.c:957]: dlg_unref_helper(): unref op on 0x567f52e0 with 1 from dlg_hash.c:975
1(17805) DEBUG: dialog [dlg_hash.c:961]: dlg_unref_helper(): unref dlg 0x567f52e0 with 1 -> 4
1(17805) DEBUG: dialog [dlg_hash.c:957]: dlg_unref_helper(): unref op on 0x567f52e0 with 1 from dlg_handlers.c:1795
1(17805) DEBUG: dialog [dlg_hash.c:961]: dlg_unref_helper(): unref dlg 0x567f52e0 with 1 -> 3
1(17805) DEBUG: dialog [dlg_hash.c:937]: dlg_ref_helper(): ref op on 0x567f52e0 with 1 from dlg_handlers.c:1409
1(17805) DEBUG: dialog [dlg_hash.c:941]: dlg_ref_helper(): ref dlg 0x567f52e0 with 1 -> 4
1(17805) DEBUG: dialog [dlg_handlers.c:1420]: dlg_onroute(): BYE successfully processed
1(17805) DEBUG: dialog [dlg_cb.c:254]: run_dlg_callbacks(): dialog=0x567f52e0, type=64
1(17805) DEBUG: uac [replace.c:919]: replace_callback(): UPSTREAM direction detected - replacing uri with the original uri
1(17805) DEBUG: uac [replace.c:935]: replace_callback(): Replace [ sip:00421221025979 at ipgate.sk] with ["0650950983" sip:0650950983 at 192.168.5.94]
1(17805) DEBUG: uac [replace.c:972]: replace_callback(): inserting display ["0650950983"]
1(17805) DEBUG: dialog [dlg_hash.c:957]: dlg_unref_helper(): unref op on 0x567f52e0 with 2 from dlg_handlers.c:1444
1(17805) DEBUG: dialog [dlg_hash.c:961]: dlg_unref_helper(): unref dlg 0x567f52e0 with 2 -> 2
1(17805) DEBUG: dialog [dlg_hash.c:957]: dlg_unref_helper(): unref op on 0x567f52e0 with 1 from dlg_hash.c:975
1(17805) DEBUG: dialog [dlg_hash.c:961]: dlg_unref_helper(): unref dlg 0x567f52e0 with 1 -> 1
1(17805) DEBUG: dialog [dlg_hash.c:712]: dlg_lookup(): ref dlg 0x567f52e0 with 1 -> 2
1(17805) DEBUG: dialog [dlg_hash.c:714]: dlg_lookup(): dialog id=8549 found on entry 3536
1(17805) DEBUG: dialog [dlg_hash.c:957]: dlg_unref_helper(): unref op on 0x567f52e0 with 1 from dlg_hash.c:975
1(17805) DEBUG: dialog [dlg_hash.c:961]: dlg_unref_helper(): unref dlg 0x567f52e0 with 1 -> 1
1(17805) DEBUG: dialog [dlg_hash.c:712]: dlg_lookup(): ref dlg 0x567f52e0 with 1 -> 2
1(17805) DEBUG: dialog [dlg_hash.c:714]: dlg_lookup(): dialog id=8549 found on entry 3536
1(17805) DEBUG: dialog [dlg_var.c:261]: print_lists(): Internal var-list ((nil)):
1(17805) DEBUG: dialog [dlg_var.c:271]: print_lists(): Dialog var-list (0x567e7b04):
1(17805) DEBUG: dialog [dlg_var.c:276]: print_lists(): acc_CoreConnectTime=1570450903.888174 (flags 1)
1(17805) DEBUG: dialog [dlg_var.c:276]: print_lists(): acc_tagPSTNOutgoing=1 (flags 1)
1(17805) DEBUG: dialog [dlg_var.c:276]: print_lists(): acc_PrivacyFlag=0 (flags 1)
1(17805) DEBUG: dialog [dlg_var.c:276]: print_lists(): acc_CallingStationID=00421221025979 (flags 1)
18(17822) DEBUG: http_async_client [async_http.c:388]: notification_socket_cb(): query received: [http://192.168.6.23:2080/cdr_http] (0x567fe4a0)
1(17805) DEBUG: dialog [dlg_var.c:276]: print_lists(): default_max_usage=7200 (flags 1)
1(17805) DEBUG: dialog [dlg_var.c:276]: print_lists(): SetupDateDestination=2019-10-07 (flags 1)
1(17805) DEBUG: dialog [dlg_var.c:276]: print_lists(): SetupTimeDestination=2019-10-07T08:21:39-04:00 (flags 1)
1(17805) DEBUG: dialog [dlg_var.c:276]: print_lists(): SetupDate=2019-10-07 (flags 1)
1(17805) DEBUG: dialog [dlg_var.c:276]: print_lists(): SetupTime=2019-10-07T14:21:39+02:00 (flags 1)
1(17805) DEBUG: dialog [dlg_var.c:276]: print_lists(): cgrOptionalParameters=
"Origination_date":"2019-10-07",
"Destination_time":"2019-10-07T08:21:39-04:00",
"Destination_date":"2019-10-07", (flags 3)
18(17822) DEBUG: http_async_client [http_multi.c:423]: new_request(): received query http://192.168.6.23:2080/cdr_http with timeout 500, tls_verify_peer 1, tls_verify_host 1 (param=0x567fe4a0)
1(17805) DEBUG: dialog [dlg_var.c:276]: print_lists(): cgrSubject=custom (flags 1)
1(17805) DEBUG: dialog [dlg_var.c:276]: print_lists(): cgrAccount=default (flags 1)
...
3(17807) DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): received on udp socket: (109/100/372) [[SIP/2.0 200 OK 0D 0A Via: SIP/2.0/UDP 192.168.5.67;branch=z9hG4bK9f07.2ab82356000000000000000000000000.0 0D ]]
1(17805) DEBUG: dialog [dlg_var.c:276]: print_lists(): acc_CoreSetupTime=1570450898.705586 (flags 1)
1(17805) DEBUG: dialog [dlg_hash.c:957]: dlg_unref_helper(): unref op on 0x567f52e0 with 1 from dlg_hash.c:975
1(17805) DEBUG: dialog [dlg_hash.c:961]: dlg_unref_helper(): unref dlg 0x567f52e0 with 1 -> 1
3(17807) DEBUG: <core> [core/parser/msg_parser.c:620]: parse_msg(): SIP Reply (status):
3(17807) DEBUG: <core> [core/parser/msg_parser.c:622]: parse_msg(): version: <SIP/2.0>
3(17807) DEBUG: <core> [core/parser/msg_parser.c:624]: parse_msg(): status: <200>
3(17807) DEBUG: <core> [core/parser/msg_parser.c:626]: parse_msg(): reason: <OK>
3(17807) DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK9f07.2ab82356000000000000000000000000.0>; state=16
3(17807) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
3(17807) DEBUG: <core> [core/parser/msg_parser.c:498]: parse_headers(): Via found, flags=2
3(17807) DEBUG: <core> [core/parser/msg_parser.c:500]: parse_headers(): this is the first via
1(17805) DEBUG: siputils [checks.c:123]: has_totag(): totag found
3(17807) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=d194da15fd712eaa6a5c49053889040c.8883
1(17805) DEBUG: rr [loose.c:91]: is_preloaded(): is_preloaded: No
3(17807) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29
1(17805) DEBUG: <core> [core/socket_info.c:564]: grep_sock_info(): checking if host==us: 12==12 && [192.168.5.94] == [192.168.5.67]
1(17805) DEBUG: <core> [core/socket_info.c:567]: grep_sock_info(): checking if port 5060 (advertise 0) matches port 5060
3(17807) DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [74]; uri=[sip:htable at 192.168.5.66:5060]
1(17805) DEBUG: <core> [core/socket_info.c:564]: grep_sock_info(): checking if host==us: 12==12 && [192.168.5.94] == [192.168.5.67]
3(17807) DEBUG: <core> [core/parser/msg_parser.c:174]: get_hdr_field(): to body [<sip:htable at 192.168.5.66:5060>], to tag [d194da15fd712eaa6a5c49053889040c.8883]
1(17805) DEBUG: <core> [core/socket_info.c:567]: grep_sock_info(): checking if port 5060 (advertise 0) matches port 5060
1(17805) DEBUG: <core> [core/forward.c:412]: check_self(): host != me
1(17805) DEBUG: <core> [core/socket_info.c:564]: grep_sock_info(): checking if host==us: 12==12 && [192.168.5.67] == [192.168.5.67]
1(17805) DEBUG: <core> [core/socket_info.c:567]: grep_sock_info(): checking if port 5060 (advertise 0) matches port 5060
1(17805) DEBUG: rr [loose.c:813]: after_loose(): Topmost route URI: 'sip:192.168.5.67;lr;ftag=er5BNQBaDav1N;did=0dd.5612' is me
1(17805) DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
18(17822) DEBUG: http_async_client [hm_hash.c:80]: build_hash_key(): received id 0x56801fc0 (4)-> 0x56801fc0 (10)
1(17805) DEBUG: rr [loose.c:182]: find_next_route(): No next Route HF found
1(17805) DEBUG: rr [loose.c:843]: after_loose(): No next URI found
1(17805) DEBUG: rr [rr_cb.c:95]: run_rr_callbacks(): callback id 1 entered with <lr;ftag=er5BNQBaDav1N;did=0dd.5612>
1(17805) DEBUG: uac [replace.c:576]: restore_uri(): getting 'vsf' Route param
1(17805) DEBUG: uac [replace.c:580]: restore_uri(): route param 'vsf' not found
1(17805) DEBUG: uac [replace.c:576]: restore_uri(): getting 'vst' Route param
1(17805) DEBUG: uac [replace.c:580]: restore_uri(): route param 'vst' not found
1(17805) DEBUG: rr [rr_cb.c:95]: run_rr_callbacks(): callback id 0 entered with <lr;ftag=er5BNQBaDav1N;did=0dd.5612>
1(17805) DEBUG: dialog [dlg_hash.c:712]: dlg_lookup(): ref dlg 0x567f52e0 with 1 -> 2
1(17805) DEBUG: dialog [dlg_hash.c:714]: dlg_lookup(): dialog id=8549 found on entry 3536
1(17805) DEBUG: dialog [dlg_hash.c:957]: dlg_unref_helper(): unref op on 0x567f52e0 with 1 from dlg_hash.c:975
1(17805) DEBUG: dialog [dlg_hash.c:961]: dlg_unref_helper(): unref dlg 0x567f52e0 with 1 -> 1
18(17822) CRITICAL: <core> [core/mem/q_malloc.c:149]: qm_debug_check_frag(): BUG: qm: prev. fragm. tail overwritten(c0003063, abcdefed)[0x97a909c4:0x97a909e0]! Memory allocator was called from http_async_client: hm_hash.c:82. Fragment marked by http_async_client: hm_hash.c:71. Exec from core/mem/q_malloc.c:384.
1(17805) DEBUG: siputils [checks.c:123]: has_totag(): totag found
1(17805) DEBUG: tm [t_lookup.c:1346]: t_newtran(): msg (0x97a9a5d4) id=52/17805 global id=52/17805 T start=0x568003ec
1(17805) DEBUG: tm [t_lookup.c:1354]: t_newtran(): transaction already in process 0x568003ec`
Maybe is the problem with curl? Thanks for any sugestions.
--
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/2091#issuecomment-539022563
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.kamailio.org/pipermail/sr-dev/attachments/20191007/6d5d7c71/attachment-0001.html>
More information about the sr-dev
mailing list