[kamailio] Module cnxcc: Error in log while parsing fake message (#324)
``` 10(21119) DEBUG: dialog [dlg_req_within.c:384]: send_bye(): BYE sent to callee 10(21119) DEBUG: dialog [dlg_hash.c:832]: dlg_unref(): unref dlg 0x808f57580 with 1 -> 2 10(21119) DEBUG: cnxcc [cnxcc_mod.c:1005]: terminate_call(): dlg_end_dlg sent to call [] 10(21119) DEBUG: cnxcc [cnxcc_sip_msg_faker.c:45]: faked_msg_init_with_dlg_info(): fake msg: OPTIONS sip:you@kamailio.org SIP/2.0 Via: SIP/2.0/UDP 127.0.0.1 From: <>;tag= To: <>;tag= Call-ID: CSeq: 1 OPTIONS Content-Length: 0 10(21119) DEBUG: <core> [parser/msg_parser.c:606]: parse_msg(): SIP Request: 10(21119) DEBUG: <core> [parser/msg_parser.c:608]: parse_msg(): method: <OPTIONS> 10(21119) DEBUG: <core> [parser/msg_parser.c:610]: parse_msg(): uri: <sip:you@kamailio.org> 10(21119) DEBUG: <core> [parser/msg_parser.c:612]: parse_msg(): version: <SIP/2.0> 10(21119) DEBUG: <core> [parser/parse_via.c:2642]: parse_via(): end of header reached, state=2 10(21119) DEBUG: <core> [parser/msg_parser.c:496]: parse_headers(): parse_headers: Via found, flags=2 10(21119) DEBUG: <core> [parser/msg_parser.c:498]: parse_headers(): parse_headers: this is the first via 10(21119) exec: *** cfgtrace:request_route=[CNXCC] c=[/usr/local/etc/kamailio/kamailio.cfg] l=777 a=26 n=xlog 10(21119) ERROR: <core> [parser/parse_addr_spec.c:764]: parse_addr_spec(): ERROR: parse_to : unexpected char [>] in status 5: <<<>> . 10(21119) ERROR: <core> [parser/msg_parser.c:165]: get_hdr_field(): ERROR: get_hdr_field: bad to header 10(21119) DEBUG: <core> [parser/msg_parser.c:280]: get_hdr_field(): get_hdr_field: error exit 10(21119) INFO: <core> [parser/msg_parser.c:338]: parse_headers(): ERROR: bad header field [To: <>;tag= Call-ID] 10(21119) ERROR: pv [pv_core.c:635]: pv_get_callid(): cannot parse Call-Id header 10(21119) INFO: <script>: [<null>]: call killed ``` it seems that the fake message values are not filled, does I miss load an special module or is it an error because of old source code. Using version 4.31. --- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/324
Do you have in the logs a message that is like "Got kill signal for call ..."? Can you paste it here? It looks like using an invalid call structure -- nor familiar with cnxcc, but from C code point of view. --- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/324#issuecomment-139506483
yes I have ``` 10(21119) DEBUG: cnxcc [cnxcc_check.c:109]: check_calls_by_money(): Client [customer1] | Ended-Calls-Credit-Spent: 0.000000 TotalCredit/MaxCredit: 10.000000/10.000000 10(21119) DEBUG: cnxcc [cnxcc_mod.c:894]: terminate_all_calls(): Killing call with CID [4Urex8OptI] 10(21119) DEBUG: cnxcc [cnxcc_mod.c:967]: terminate_call(): Got kill signal for call [4Urex8OptI] client [customer1] h_id [2908] h_entry [970]. Dropping it now 10(21119) DEBUG: dialog [dlg_req_within.c:496]: mi_terminate_dlg(): h_entry 970 h_id 2908 10(21119) DEBUG: dialog [dlg_hash.c:614]: dlg_lookup(): ref dlg 0x808f57580 with 1 -> 3 10(21119) DEBUG: dialog [dlg_hash.c:616]: dlg_lookup(): dialog id=2908 found on entry 970 10(21119) DEBUG: dialog [dlg_cb.c:254]: run_dlg_callbacks(): dialog=0x808f57580, type=64 10(21119) DEBUG: cnxcc [cnxcc_mod.c:452]: __dialog_terminated_callback(): Dialog terminated for CID [4Urex8OptI] 10(21119) DEBUG: cnxcc [cnxcc_mod.c:634]: __stop_billing(): Call [4Urex8OptI] of client-ID [customer1], ended 10(21119) DEBUG: cnxcc [cnxcc_mod.c:910]: __free_call(): Freeing call [4Urex8OptI] 10(21119) DEBUG: cnxcc [cnxcc_mod.c:673]: __stop_billing(): Removing client [customer1] and its calls from the list 10(21119) DEBUG: cnxcc [cnxcc_redis.c:313]: redis_get_int(): Got INT value: number_of_calls=0i 10(21119) DEBUG: dialog [dlg_req_within.c:351]: send_bye(): sending BYE to caller 10(21119) DEBUG: tm [uac.c:249]: t_uac_prepare(): DEBUG:tm:t_uac: next_hop=<sip:+494020001@5.159.56.231> 10(21119) DEBUG: tm [uac.c:150]: dlg2hash(): DEBUG: dlg2hash: 13313 10(21119) DEBUG: dialog [dlg_req_within.c:384]: send_bye(): BYE sent to caller 10(21119) DEBUG: dialog [dlg_req_within.c:351]: send_bye(): sending BYE to callee 10(21119) DEBUG: tm [uac.c:249]: t_uac_prepare(): DEBUG:tm:t_uac: next_hop=<sip:+494010001@5.159.56.252:52708> 10(21119) DEBUG: tm [uac.c:150]: dlg2hash(): DEBUG: dlg2hash: 26695 ``` i seems that the call data is deleted bevor executing the faked_msg_init_with_dlg_info() function is called. --- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/324#issuecomment-139513871
Indeed, it seems that terminate_call() triggers ending of the dialog, which call backs deletion of call structure from cnxcc. But after the part ending of the dialog, cnxcc executes __notify_call_termination(&call->sip_data), accessing the data of the call just deleted. For me, it looks like __notify_call_termination(&call->sip_data) should be executed before ending the dialog via MI in terminate_call(), or at least, the fake msg needed inside __notify_call_termination() has to be built before. Maybe @caruizdiaz can review and propose a fix, being the architect and developer of the module. --- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/324#issuecomment-140030661
Where can i find information for help fixing the module? --- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/324#issuecomment-140693743
Look at the source code for terminate_call() function inside modules/cnxcc/cnxcc_mod.c --- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/324#issuecomment-140697213
Any more information about how a module have to be build? Cause this module seems to be real broken. ``` 0(52565) INFO: <script>: Setting up money based credit control 0(52565) INFO: cnxcc [cnxcc_redis.c:72]: redis_get_or_create_credit_data(): credit_data with ID=[customer1] DOES exist in the cluster, retrieving it... 0(52565) INFO: cnxcc [cnxcc_redis.c:351]: redis_get_str(): Got STRING value: consumed_amount=[0.000000] 0(52565) INFO: cnxcc [cnxcc_redis.c:351]: redis_get_str(): Got STRING value: ended_calls_consumed_amount=[0.000000] 0(52565) INFO: cnxcc [cnxcc_redis.c:351]: redis_get_str(): Got STRING value: max_amount=[10.000000] Fatal error 'mutex is on list' at line 424 in file /usr/src/lib/libthr/thread/thr_mutex.c (errno = 0) 0(52565) ALERT: <core> [main.c:728]: handle_sigs(): child process 52571 exited by a signal 6 0(52565) ALERT: <core> [main.c:731]: handle_sigs(): core was generated 0(52565) INFO: <core> [main.c:740]: handle_sigs(): dont_fork turned on, living on ``` --- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/324#issuecomment-140773653
Do you have **fork=no** in config file? Change that to fork=yes, perhaps the module is not done for non-forking mode. If not the above, as you got a core dump, you can use gdb to get the output of 'bt full' from the core file. --- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/324#issuecomment-140776586
No I didn't have __fork=no__ in the config, I was starting kamailio from the command line with _kamailio -Ee -D_ ``` (gdb) bt full #0 0x0000000801118d2a in thr_kill () from /lib/libc.so.7 No symbol table info available. #1 0x0000000801118c96 in raise () from /lib/libc.so.7 No symbol table info available. #2 0x0000000801117489 in abort () from /lib/libc.so.7 No symbol table info available. #3 0x0000000800dc363a in pthread_attr_getaffinity_np () from /lib/libthr.so.3 No symbol table info available. #4 0x0000000800dbee66 in pthread_mutex_destroy () from /lib/libthr.so.3 No symbol table info available. #5 0x0000000807ce816f in check_calls_by_money () from /usr/local/lib/kamailio/modules/cnxcc.so No symbol table info available. #6 0x000000000076acb7 in fork_basic_timer () No symbol table info available. #7 0x0000000807cb4c45 in rpc_active_clients () from /usr/local/lib/kamailio/modules/cnxcc.so No symbol table info available. #8 0x000000000050485b in init_child () No symbol table info available. #9 0x00000000005042da in init_child () No symbol table info available. #10 0x00000000005042da in init_child () No symbol table info available. #11 0x00000000005042da in init_child () No symbol table info available. #12 0x00000000005042da in init_child () No symbol table info available. #13 0x000000000050428a in init_child () No symbol table info available. #14 0x000000000052342e in main_loop () No symbol table info available. #15 0x0000000000531ea4 in main () No symbol table info available. ``` --- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/324#issuecomment-140781864
The option **-D** sets fork=no and I see cnxcc tries to fork, needing extra processes. Remove that from command line. --- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/324#issuecomment-140782730
even when removing it, it crashes ``` 3(52703) INFO: <script>: Setting up money based credit control 1(52701) INFO: <script>: Setting up money based credit control 1(52701) WARNING: cnxcc [cnxcc_mod.c:1374]: __add_call_by_cid(): value cid: len=44 | value [003f309d-f75a-e511-81cd-843a4b6087c4@1337b0x] 1(52701) WARNING: cnxcc [cnxcc_mod.c:1375]: __add_call_by_cid(): added cid: len=44 | value [003f309d-f75a-e511-81cd-843a4b6087c4@1337b0x] Fatal error 'mutex is on list' at line 424 in file /usr/src/lib/libthr/thread/thr_mutex.c (errno = 35) 10(52710) INFO: cnxcc [cnxcc_check.c:96]: check_calls_by_money(): ec=10.000000, ca=0.000000, ca2=10.000000 10(52710) ERROR: cnxcc [cnxcc_mod.c:1013]: terminate_call(): Error executing dlg_end_dlg command. Return code was [404] 10(52710) ERROR: <core> [parser/parse_addr_spec.c:764]: parse_addr_spec(): ERROR: parse_to : unexpected char [>] in status 5: <<<>> . 10(52710) ERROR: <core> [parser/msg_parser.c:165]: get_hdr_field(): ERROR: get_hdr_field: bad to header 10(52710) INFO: <core> [parser/msg_parser.c:338]: parse_headers(): ERROR: bad header field [To: <>;tag= Call-ID] 10(52710) ERROR: pv [pv_core.c:635]: pv_get_callid(): cannot parse Call-Id header 10(52710) INFO: <script>: [<null>]: call killed 10(52710) ERROR: cnxcc [cnxcc_mod.c:1013]: terminate_call(): Error executing dlg_end_dlg command. Return code was [404] 10(52710) INFO: cnxcc [cnxcc_check.c:96]: check_calls_by_money(): ec=10.000000, ca=0.000000, ca2=10.000000 10(52710) ERROR: cnxcc [cnxcc_mod.c:1013]: terminate_call(): Error executing dlg_end_dlg command. Return code was [404] 10(52710) ERROR: cnxcc [cnxcc_mod.c:1013]: terminate_call(): Error executing dlg_end_dlg command. Return code was [404] 10(52710) INFO: cnxcc [cnxcc_check.c:96]: check_calls_by_money(): ec=10.000000, ca=0.000000, ca2=10.000000 10(52710) ERROR: cnxcc [cnxcc_mod.c:1013]: terminate_call(): Error executing dlg_end_dlg command. Return code was [404] 10(52710) ERROR: cnxcc [cnxcc_mod.c:1013]: terminate_call(): Error executing dlg_end_dlg command. Return code was [404] 10(52710) INFO: cnxcc [cnxcc_check.c:96]: check_calls_by_money(): ec=10.000000, ca=0.000000, ca2=10.000000 10(52710) ERROR: cnxcc [cnxcc_mod.c:1013]: terminate_call(): Error executing dlg_end_dlg command. Return code was [404] 10(52710) ERROR: cnxcc [cnxcc_mod.c:1013]: terminate_call(): Error executing dlg_end_dlg command. Return code was [404] 10(52710) INFO: cnxcc [cnxcc_check.c:96]: check_calls_by_money(): ec=10.000000, ca=0.000000, ca2=10.000000 10(52710) ERROR: cnxcc [cnxcc_mod.c:1013]: terminate_call(): Error executing dlg_end_dlg command. Return code was [404] 10(52710) ERROR: cnxcc [cnxcc_mod.c:1013]: terminate_call(): Error executing dlg_end_dlg command. Return code was [404] 10(52710) INFO: cnxcc [cnxcc_check.c:96]: check_calls_by_money(): ec=10.000000, ca=0.000000, ca2=10.000000 10(52710) ERROR: cnxcc [cnxcc_mod.c:1013]: terminate_call(): Error executing dlg_end_dlg command. Return code was [404] 10(52710) ERROR: cnxcc [cnxcc_mod.c:1013]: terminate_call(): Error executing dlg_end_dlg command. Return code was [404] 10(52710) INFO: cnxcc [cnxcc_check.c:96]: check_calls_by_money(): ec=10.000000, ca=0.000000, ca2=10.000000 10(52710) ERROR: cnxcc [cnxcc_mod.c:1013]: terminate_call(): Error executing dlg_end_dlg command. Return code was [404] 10(52710) ERROR: cnxcc [cnxcc_mod.c:1013]: terminate_call(): Error executing dlg_end_dlg command. Return code was [404] 10(52710) INFO: cnxcc [cnxcc_check.c:96]: check_calls_by_money(): ec=10.000000, ca=0.000000, ca2=10.000000 10(52710) ERROR: cnxcc [cnxcc_mod.c:1013]: terminate_call(): Error executing dlg_end_dlg command. Return code was [404] 10(52710) ERROR: cnxcc [cnxcc_mod.c:1013]: terminate_call(): Error executing dlg_end_dlg command. Return code was [404] 10(52710) INFO: cnxcc [cnxcc_check.c:96]: check_calls_by_money(): ec=10.000000, ca=0.000000, ca2=10.000000 10(52710) ERROR: cnxcc [cnxcc_mod.c:1013]: terminate_call(): Error executing dlg_end_dlg command. Return code was [404] 10(52710) ERROR: cnxcc [cnxcc_mod.c:1013]: terminate_call(): Error executing dlg_end_dlg command. Return code was [404] 10(52710) INFO: cnxcc [cnxcc_check.c:96]: check_calls_by_money(): ec=10.000000, ca=0.000000, ca2=10.000000 10(52710) ERROR: cnxcc [cnxcc_mod.c:1013]: terminate_call(): Error executing dlg_end_dlg command. Return code was [404] 10(52710) ERROR: cnxcc [cnxcc_mod.c:1013]: terminate_call(): Error executing dlg_end_dlg command. Return code was [404] 18(52718) CRITICAL: <core> [pass_fd.c:275]: receive_fd(): EOF on 10 0(52700) ALERT: <core> [main.c:728]: handle_sigs(): child process 52701 exited by a signal 6 0(52700) ALERT: <core> [main.c:731]: handle_sigs(): core was generated 0(52700) INFO: <core> [main.c:743]: handle_sigs(): terminating due to SIGCHLD 18(52718) INFO: <core> [main.c:794]: sig_usr(): signal 15 received 10(52710) INFO: <core> [main.c:794]: sig_usr(): signal 15 received 15(52715) INFO: <core> [main.c:794]: sig_usr(): signal 15 received 14(52714) INFO: <core> [main.c:794]: sig_usr(): signal 15 received 13(52713) INFO: <core> [main.c:794]: sig_usr(): signal 15 received 12(52712) INFO: <core> [main.c:794]: sig_usr(): signal 15 received 11(52711) INFO: <core> [main.c:794]: sig_usr(): signal 15 received 9(52709) INFO: <core> [main.c:794]: sig_usr(): signal 15 received 8(52708) INFO: <core> [main.c:794]: sig_usr(): signal 15 received 6(52706) INFO: <core> [main.c:794]: sig_usr(): signal 15 received 5(52705) INFO: <core> [main.c:794]: sig_usr(): signal 15 received 3(52703) INFO: <core> [main.c:794]: sig_usr(): signal 15 received 2(52702) INFO: <core> [main.c:794]: sig_usr(): signal 15 received 7(52707) INFO: <core> [main.c:794]: sig_usr(): signal 15 received 4(52704) INFO: <core> [main.c:794]: sig_usr(): signal 15 received 16(52716) INFO: <core> [main.c:794]: sig_usr(): signal 15 received 17(52717) INFO: <core> [main.c:794]: sig_usr(): signal 15 received ``` --- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/324#issuecomment-140784073
Get the backtrace from the last core file, it should be different now. I am not the developer of this module, I will try to figure out the issue from the C code point of view and at least make it safe to run. It still can be related to the improper usage of faked_msg_init_with_dlg_info() --- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/324#issuecomment-140790895
``` (gdb) bt full #0 0x0000000801118d2a in thr_kill () from /lib/libc.so.7 No symbol table info available. #1 0x0000000801118c96 in raise () from /lib/libc.so.7 No symbol table info available. #2 0x0000000801117489 in abort () from /lib/libc.so.7 No symbol table info available. #3 0x0000000800dc363a in pthread_attr_getaffinity_np () from /lib/libthr.so.3 No symbol table info available. #4 0x0000000800dbee66 in pthread_mutex_destroy () from /lib/libthr.so.3 No symbol table info available. #5 0x0000000807ce816f in check_calls_by_money () from /usr/local/lib/kamailio/modules/cnxcc.so No symbol table info available. #6 0x000000000076acb7 in fork_basic_timer () No symbol table info available. #7 0x0000000807cb4c45 in rpc_active_clients () from /usr/local/lib/kamailio/modules/cnxcc.so No symbol table info available. #8 0x000000000050485b in init_child () No symbol table info available. #9 0x00000000005042da in init_child () No symbol table info available. #10 0x00000000005042da in init_child () No symbol table info available. #11 0x00000000005042da in init_child () No symbol table info available. #12 0x00000000005042da in init_child () No symbol table info available. #13 0x000000000050428a in init_child () No symbol table info available. #14 0x000000000052342e in main_loop () No symbol table info available. #15 0x0000000000531ea4 in main () No symbol table info available. ``` --- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/324#issuecomment-140791634
This is the old core. Do you have a new file? If not, delete this one and start again to get a new one. --- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/324#issuecomment-140795005
Sorry I haven't seen that it was the old one. ``` Fatal error 'mutex is on list' at line 424 in file /usr/src/lib/libthr/thread/thr_mutex.c (errno = 0) 4(70345) INFO: <script>: Setting up money based credit control 18(70359) CRITICAL: <core> [pass_fd.c:275]: receive_fd(): EOF on 19 0(70341) ALERT: <core> [main.c:728]: handle_sigs(): child process 70351 exited by a signal 6 0(70341) ALERT: <core> [main.c:731]: handle_sigs(): core was generated 0(70341) INFO: <core> [main.c:743]: handle_sigs(): terminating due to SIGCHLD ``` ``` (gdb) bt full #0 0x0000000801118d2a in thr_kill () from /lib/libc.so.7 No symbol table info available. #1 0x0000000801118c96 in raise () from /lib/libc.so.7 No symbol table info available. #2 0x0000000801117489 in abort () from /lib/libc.so.7 No symbol table info available. #3 0x0000000800dc363a in pthread_attr_getaffinity_np () from /lib/libthr.so.3 No symbol table info available. #4 0x0000000800dbee66 in pthread_mutex_destroy () from /lib/libthr.so.3 No symbol table info available. #5 0x000000080488d175 in rpc_reply () from /usr/local/lib/kamailio/modules/tm.so No symbol table info available. #6 0x0000000804870878 in tm_reply_mutex_lock () from /usr/local/lib/kamailio/modules/tm.so No symbol table info available. #7 0x00000008048875ea in t_reply_with_body () from /usr/local/lib/kamailio/modules/tm.so No symbol table info available. #8 0x0000000804870b51 in t_reply () from /usr/local/lib/kamailio/modules/tm.so No symbol table info available. #9 0x0000000804870961 in t_reply () from /usr/local/lib/kamailio/modules/tm.so No symbol table info available. #10 0x0000000804802f38 in t_relay_to () from /usr/local/lib/kamailio/modules/tm.so No symbol table info available. #11 0x00000008048697f8 in t_check_trans () from /usr/local/lib/kamailio/modules/tm.so No symbol table info available. #12 0x0000000804858ee1 in t_check_trans () from /usr/local/lib/kamailio/modules/tm.so No symbol table info available. #13 0x0000000000478c62 in do_action () No symbol table info available. #14 0x000000000048c228 in run_actions () No symbol table info available. #15 0x000000000048ce76 in run_actions_safe () No symbol table info available. #16 0x000000000067730a in rval_get_int () No symbol table info available. #17 0x000000000067aed7 in rval_expr_eval_int () No symbol table info available. #18 0x000000000067b568 in rval_expr_eval_int () No symbol table info available. #19 0x00000000004784a0 in do_action () No symbol table info available. #20 0x000000000048c228 in run_actions () No symbol table info available. #21 0x0000000000473238 in do_action () No symbol table info available. #22 0x000000000048c228 in run_actions () No symbol table info available. #23 0x0000000000473238 in do_action () No symbol table info available. #24 0x000000000048c228 in run_actions () No symbol table info available. #25 0x000000000048cf69 in run_top_route () No symbol table info available. #26 0x000000000045f986 in receive_msg () No symbol table info available. #27 0x0000000000619c40 in udp_rcv_loop () No symbol table info available. #28 0x0000000000526486 in main_loop () No symbol table info available. #29 0x0000000000531ea4 in main () No symbol table info available. ``` It doesn't crash right away but after some calls made --- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/324#issuecomment-140991039
How did you install kamailio? The debugging symbols are missing. --- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/324#issuecomment-141006624
It was build from source --- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/324#issuecomment-141454270
I pushed a patch to attempt to fix the case, can you try with latest git master branch? --- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/324#issuecomment-141834760
Re-open if after the last patch there are still issues. --- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/324#issuecomment-144036161
Closed #324. --- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/324#event-421786706
Sadly I had no spare time to test it but I will do it this week. Thanks in advance, for the time spend on it. --- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/324#issuecomment-147824743
participants (2)
-
Daniel-Constantin Mierla -
Rick