[kamailio] Module cnxcc: Error in log while parsing fake message (#324)

List overview All Threads
Download

newer

older

[kamailio] Use the Additional...

4.3 branch gcc warnings

Rick

11 Sep 2015 11 Sep '15

9:32 a.m.

``` 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

Attachments:

attachment.html (text/html — 2.8 KB)

Show replies by date

Daniel-Constantin Mierla

11 Sep 11 Sep

10:08 a.m.

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

Rick

10:44 a.m.

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

Daniel-Constantin Mierla

14 Sep 14 Sep

10:29 a.m.

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

Rick

16 Sep 16 Sep

10:01 a.m.

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

Daniel-Constantin Mierla

10:19 a.m.

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

Rick

3:18 p.m.

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

Daniel-Constantin Mierla

3:27 p.m.

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

Rick

3:43 p.m.

No I didn't have __fork=no__ in the config, I was starting kamailio from the command line with _kamailio -Ee -D_

--- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/324#issuecomment-140781864

Daniel-Constantin Mierla

3:46 p.m.

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

Rick

3:52 p.m.

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

Daniel-Constantin Mierla

4:12 p.m.

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

Rick

4:15 p.m.

--- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/324#issuecomment-140791634

Daniel-Constantin Mierla

4:29 p.m.

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

Rick

17 Sep 17 Sep

7:25 a.m.

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

Daniel-Constantin Mierla

8:39 a.m.

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

Rick

18 Sep 18 Sep

1:39 p.m.

It was build from source

--- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/324#issuecomment-141454270

Daniel-Constantin Mierla

20 Sep 20 Sep

9:19 p.m.

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

Daniel-Constantin Mierla

29 Sep 29 Sep

11:52 a.m.

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

Daniel-Constantin Mierla

11:52 a.m.

Closed #324.

--- Reply to this email directly or view it on GitHub: https://github.com/kamailio/kamailio/issues/324#event-421786706

Rick

13 Oct 13 Oct

7:31 p.m.

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

3467

Age (days ago)

3499

Last active (days ago)

sr-dev@lists.kamailio.org

20 comments

2 participants

tags (0)

participants (2)

Daniel-Constantin Mierla
Rick