Hi all,
I've tested the current release candidate for Kamailio these days and found that the presence/dialog state functionality is not given in the current version.
The first (and worst) difference to the latest stable release is that the handling of "setflag(X)" for tracing the dialogs resulted in a crash of kamailio with following error message:
********************** EXCERPT ****************** Nov 24 13:35:47 lennysrv /usr/local/sbin/kamailio[13814]: : tm [t_hooks.c:190]: BUG:tm:register_tmcb: callback type TMCB_REQUEST_IN can't be register along with types Nov 24 13:35:47 lennysrv /usr/local/sbin/kamailio[13814]: ERROR: dialog [dlg_handlers.c:615]: failed cache in T the shortcut to dlg Nov 24 13:35:53 lennysrv /usr/local/sbin/kamailio[13815]: NOTICE: acc [acc.c:275]: ACC: call missed: timestamp=1259134133;method=INVITE;from_tag=4051501197-3958320-1259134127622;to_tag=3762694574-3958280-1259134127622;call_id=140363298-3958320-1259134127622@10.16.48.60;code=603;reason=Decline;src_user=5003;src_domain=10.16.48.205;dst_ouser=5002;dst_user=5002;dst_domain=10.16.48.60 Nov 24 13:35:56 lennysrv /usr/local/sbin/kamailio[13815]: INFO: pua_usrloc [ul_publish.c:203]: should not send ul publish Nov 24 13:35:56 lennysrv /usr/local/sbin/kamailio[13815]: INFO: <script>: --- pua-set-publish() was executed --- Nov 24 13:35:58 lennysrv kernel: [176699.348059] kamailio[13821]: segfault at c0c0c0c0 ip b7de43b3 sp bfb03eb8 error 5 in libc-2.7.so[b7d6e000+155000] Nov 24 13:35:58 lennysrv /usr/local/sbin/kamailio[13837]: : <core> [pass_fd.c:283]: ERROR: receive_fd: EOF on 12 Nov 24 13:35:58 lennysrv /usr/local/sbin/kamailio[13812]: ALERT: <core> [main.c:721]: child process 13821 exited by a signal 11 Nov 24 13:35:58 lennysrv /usr/local/sbin/kamailio[13812]: ALERT: <core> [main.c:724]: core was generated Nov 24 13:35:58 lennysrv /usr/local/sbin/kamailio[13812]: INFO: <core> [main.c:736]: INFO: terminating due to SIGCHLD Nov 24 13:35:58 lennysrv /usr/local/sbin/kamailio[13814]: INFO: <core> [main.c:787]: INFO: signal 15 received ***************************************************
However, the module documentation of the source code (READMEs) does not include major news. The configuration is "the same" (regarding handle_publish, handle_subscribe, pua_set_publish) as I've used in the kamailio-1.5.3 version. But - no NOTIFY messages with XML bodies are sent to the subscribers / watchers. Instead of using the setflag(X) method I´ve tried using the method "dlg_setflag(X)" for prohibiting crashes - that was accepted by kamailio.
Were these modules tested (in combination with the dialog module) in the new version 3.0 RC1? - presence - presence_xml - presence_dialoginfo - pua - pua_dialoginfo - pua_usrloc
It does not work in the SER variant of sip-router, too. Yesterday I've downloaded the current version with GIT, compiled the code, adapted the configuration. But the result is the same as with kamailio-3 RC1 (crash and no XML).
For being sure that I have not made any mistake in the configuration, I've tested the functionality in the version 1.5.3 of Kamailio today. It works fine - the subscribers receive NOTIFY messages with XML body after every PRESENCE and DIALOG state change.
Can anybody give me a hint? Thanks in advance!
regards,
Klaus
P.S. the tested versions:
PROBLEMS: ======== version: kamailio 3.0.0-rc1 (i386/linux) 78f069 flags: STATS: Off, USE_IPV6, USE_TCP, USE_TLS, TLS_HOOKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, DBG_QM_MALLOC, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST, HAVE_RESOLV_RES ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535 poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. @(#) $Id$ main.c compiled on 13:34:37 Nov 20 2009 with gcc 4.3.2
version: ser 2.99.99-pre3 (i386/linux) flags: STATS: Off, USE_IPV6, USE_TCP, USE_TLS, TLS_HOOKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, DBG_QM_MALLOC, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST, HAVE_RESOLV_RES ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535 poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. @(#) $Id$ main.c compiled on 11:12:49 Nov 23 2009 with gcc 4.3.2
SUCCESS: ======= version: kamailio 1.5.3-notls (i386/linux) flags: STATISTICS, USE_IPV6, USE_TCP, DISABLE_NAGLE, USE_MCAST, SHM_MMAP, PKG_MALLOC, F_MALLOC, FAST_LOCK-ADAPTIVE_WAIT ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535, PKG_SIZE 4194304 poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. svnrevision: unknown @(#) $Id: main.c 5608 2009-02-13 16:48:17Z henningw $ main.c compiled on 13:31:21 Nov 24 2009 with gcc 4.3.2
Hello,
can you get the latest git. I just did a fix, I haven't tested the dialoginfo presence module yet, the problem was in some checks in tm.
However, not sure the crash was related. Can you send the backtrace?
gdb /path/to/kamailio core
then: bt
Cheers, Daniel
On 25.11.2009 8:42 Uhr, klaus.feichtinger@gmx.net wrote:
Hi all,
I've tested the current release candidate for Kamailio these days and found that the presence/dialog state functionality is not given in the current version.
The first (and worst) difference to the latest stable release is that the handling of "setflag(X)" for tracing the dialogs resulted in a crash of kamailio with following error message:
********************** EXCERPT ****************** Nov 24 13:35:47 lennysrv /usr/local/sbin/kamailio[13814]: : tm [t_hooks.c:190]: BUG:tm:register_tmcb: callback type TMCB_REQUEST_IN can't be register along with types Nov 24 13:35:47 lennysrv /usr/local/sbin/kamailio[13814]: ERROR: dialog [dlg_handlers.c:615]: failed cache in T the shortcut to dlg Nov 24 13:35:53 lennysrv /usr/local/sbin/kamailio[13815]: NOTICE: acc [acc.c:275]: ACC: call missed: timestamp=1259134133;method=INVITE;from_tag=4051501197-3958320-1259134127622;to_tag=3762694574-3958280-1259134127622;call_id=140363298-3958320-1259134127622@10.16.48.60;code=603;reason=Decline;src_user=5003;src_domain=10.16.48.205;dst_ouser=5002;dst_user=5002;dst_domain=10.16.48.60 Nov 24 13:35:56 lennysrv /usr/local/sbin/kamailio[13815]: INFO: pua_usrloc [ul_publish.c:203]: should not send ul publish Nov 24 13:35:56 lennysrv /usr/local/sbin/kamailio[13815]: INFO: <script>: --- pua-set-publish() was executed --- Nov 24 13:35:58 lennysrv kernel: [176699.348059] kamailio[13821]: segfault at c0c0c0c0 ip b7de43b3 sp bfb03eb8 error 5 in libc-2.7.so[b7d6e000+155000] Nov 24 13:35:58 lennysrv /usr/local/sbin/kamailio[13837]: : <core> [pass_fd.c:283]: ERROR: receive_fd: EOF on 12 Nov 24 13:35:58 lennysrv /usr/local/sbin/kamailio[13812]: ALERT: <core> [main.c:721]: child process 13821 exited by a signal 11 Nov 24 13:35:58 lennysrv /usr/local/sbin/kamailio[13812]: ALERT: <core> [main.c:724]: core was generated Nov 24 13:35:58 lennysrv /usr/local/sbin/kamailio[13812]: INFO: <core> [main.c:736]: INFO: terminating due to SIGCHLD Nov 24 13:35:58 lennysrv /usr/local/sbin/kamailio[13814]: INFO: <core> [main.c:787]: INFO: signal 15 received
However, the module documentation of the source code (READMEs) does not include major news. The configuration is "the same" (regarding handle_publish, handle_subscribe, pua_set_publish) as I've used in the kamailio-1.5.3 version. But - no NOTIFY messages with XML bodies are sent to the subscribers / watchers. Instead of using the setflag(X) method I´ve tried using the method "dlg_setflag(X)" for prohibiting crashes - that was accepted by kamailio.
Were these modules tested (in combination with the dialog module) in the new version 3.0 RC1?
- presence
- presence_xml
- presence_dialoginfo
- pua
- pua_dialoginfo
- pua_usrloc
It does not work in the SER variant of sip-router, too. Yesterday I've downloaded the current version with GIT, compiled the code, adapted the configuration. But the result is the same as with kamailio-3 RC1 (crash and no XML).
For being sure that I have not made any mistake in the configuration, I've tested the functionality in the version 1.5.3 of Kamailio today. It works fine - the subscribers receive NOTIFY messages with XML body after every PRESENCE and DIALOG state change.
Can anybody give me a hint? Thanks in advance!
regards,
Klaus
P.S. the tested versions:
PROBLEMS:
version: kamailio 3.0.0-rc1 (i386/linux) 78f069 flags: STATS: Off, USE_IPV6, USE_TCP, USE_TLS, TLS_HOOKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, DBG_QM_MALLOC, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST, HAVE_RESOLV_RES ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535 poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. @(#) $Id$ main.c compiled on 13:34:37 Nov 20 2009 with gcc 4.3.2
version: ser 2.99.99-pre3 (i386/linux) flags: STATS: Off, USE_IPV6, USE_TCP, USE_TLS, TLS_HOOKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, DBG_QM_MALLOC, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST, HAVE_RESOLV_RES ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535 poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. @(#) $Id$ main.c compiled on 11:12:49 Nov 23 2009 with gcc 4.3.2
SUCCESS:
version: kamailio 1.5.3-notls (i386/linux) flags: STATISTICS, USE_IPV6, USE_TCP, DISABLE_NAGLE, USE_MCAST, SHM_MMAP, PKG_MALLOC, F_MALLOC, FAST_LOCK-ADAPTIVE_WAIT ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535, PKG_SIZE 4194304 poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. svnrevision: unknown @(#) $Id: main.c 5608 2009-02-13 16:48:17Z henningw $ main.c compiled on 13:31:21 Nov 24 2009 with gcc 4.3.2
Hello,
today I've tested the current version of sip-router (version: ser 2.99.99-pre3 (i386/linux) 470d30) again with the dialog module. I found that the problem is independent of presence/dialog-state information based on subscribe/notify. As soon as the dialog module and the setflag() function for the dlg_flag is used, the server seems to have problems with the BYE message / closing the dialog.
I've done debugging with dbg and the backtrace of the tool is as follows:
(gdb) bt #0 0xb7f1d424 in __kernel_vsyscall () #1 0xb7dcd640 in raise () from /lib/i686/cmov/libc.so.6 #2 0xb7dcf018 in abort () from /lib/i686/cmov/libc.so.6 #3 0x08153dae in qm_free (qm=0xb5773000, p=0xb5910068, file=0xb794b759 "dialog: dlg_hash.c", func=0xb794c035 "destroy_dlg", line=163) at mem/q_malloc.c:447 #4 0xb7934549 in destroy_dlg (dlg=0xb590ff38) at dlg_hash.c:163 #5 0xb7936769 in unref_dlg (dlg=0xb590ff38, cnt=1) at dlg_hash.c:565 #6 0xb793b21d in profile_cleanup (msg=0x82c9d8c, flags=2147483649, param=0x0) at dlg_profile.c:307 #7 0x080e9668 in exec_post_script_cb (msg=0x82c9d8c, type=REQUEST_CB_TYPE) at script_cb.c:195 #8 0x080c5228 in receive_msg ( buf=0x8258940 "BYE sip:5002@10.16.48.60:5071 SIP/2.0\r\nVia: SIP/2.0/UDP 10.16.48.60:5072;rport;branch=z9hG4bK2740720758\r\nRoute: sip:10.16.48.205;lr=on;did=ad4.5f3b1a65\r\nFrom: sip:5003@10.16.48.205;tag=3876329704-"..., len=463, rcv_info=0xbfd38bd8) at receive.c:211 #9 0x08145bc3 in udp_rcv_loop () at udp_server.c:527 #10 0x080997a7 in main_loop () at main.c:1454 #11 0x0809c56b in main (argc=3, argv=0xbfd38e64) at main.c:2251 (gdb)
The original server error messages were:
####################################################################### 1(30934) DEBUG: <core> [forward.c:517]: orig. len=462, new_len=457, proto=1 1(30934) DEBUG: dialog [dlg_hash.c:565]: unref dlg 0xb590ff38 with 1 -> 2 1(30934) DEBUG: <core> [usr_avp.c:636]: DEBUG:destroy_avp_list: destroying list (nil) 1(30934) DEBUG: <core> [usr_avp.c:636]: DEBUG:destroy_avp_list: destroying list (nil) 1(30934) DEBUG: <core> [usr_avp.c:636]: DEBUG:destroy_avp_list: destroying list (nil) 1(30934) DEBUG: <core> [usr_avp.c:636]: DEBUG:destroy_avp_list: destroying list (nil) 1(30934) DEBUG: <core> [usr_avp.c:636]: DEBUG:destroy_avp_list: destroying list (nil) 1(30934) DEBUG: <core> [usr_avp.c:636]: DEBUG:destroy_avp_list: destroying list (nil) 1(30934) DEBUG: <core> [receive.c:267]: receive_msg: cleaning up 3(30936) DEBUG: dialog [dlg_hash.c:622]: unref dlg 0xb590ff38 with 1 -> 1 3(30936) DEBUG: dialog [dlg_hash.c:734]: dialog 0xb590ff38 changed from state 4 to state 4, due event 1 1(30934) DEBUG: <core> [parser/msg_parser.c:621]: SIP Request: 1(30934) DEBUG: <core> [parser/msg_parser.c:623]: method: <BYE> 1(30934) DEBUG: <core> [parser/msg_parser.c:625]: uri: sip:5002@10.16.48.60:5071 1(30934) DEBUG: <core> [parser/msg_parser.c:627]: version: <SIP/2.0> 1(30934) DEBUG: <core> [parser/parse_via.c:1287]: Found param type 235, <rport> = <n/a>; state=6 1(30934) DEBUG: <core> [parser/parse_via.c:1287]: Found param type 232, <branch> = <z9hG4bK2740720758>; state=16 1(30934) DEBUG: <core> [parser/parse_via.c:2300]: end of header reached, state=5 1(30934) DEBUG: <core> [parser/msg_parser.c:509]: parse_headers: Via found, flags=2 1(30934) DEBUG: <core> [parser/msg_parser.c:511]: parse_headers: this is the first via 1(30934) DEBUG: <core> [receive.c:140]: After parse_msg... 1(30934) DEBUG: <core> [receive.c:179]: preparing to run routing scripts... 1(30934) DEBUG: <core> [parser/parse_to.c:174]: DEBUG: add_param: tag=1718402625-3958280-1259324882918 1(30934) DEBUG: <core> [parser/parse_to.c:781]: end of header reached, state=29 1(30934) DEBUG: <core> [parser/msg_parser.c:185]: DEBUG: get_hdr_field: <To> [67]; uri=[sip:5002@10.16.48.205] 1(30934) DEBUG: <core> [parser/msg_parser.c:187]: DEBUG: to body [test sip:5002@10.16.48.205] 1(30934) DEBUG: <core> [parser/msg_parser.c:165]: get_hdr_field: cseq <CSeq>: <21> <BYE> 1(30934) DEBUG: maxfwd [mf_funcs.c:85]: value = 70 1(30934) DEBUG: siputils [checks.c:76]: totag found 1(30934) DEBUG: rr [loose.c:85]: is_preloaded: No 1(30934) DEBUG: <core> [socket_info.c:491]: grep_sock_info - checking if host==us: 11==12 && [10.16.48.60] == [10.16.48.205] 1(30934) DEBUG: <core> [socket_info.c:494]: grep_sock_info - checking if port 5060 matches port 5071 1(30934) DEBUG: <core> [forward.c:362]: check_self: host != me 1(30934) DEBUG: <core> [socket_info.c:491]: grep_sock_info - checking if host==us: 12==12 && [10.16.48.205] == [10.16.48.205] 1(30934) DEBUG: <core> [socket_info.c:494]: grep_sock_info - checking if port 5060 matches port 5060 1(30934) DEBUG: rr [loose.c:781]: Topmost route URI: 'sip:10.16.48.205;lr=on;did=ad4.5f3b1a65' is me 1(30934) DEBUG: <core> [parser/msg_parser.c:199]: DEBUG: get_hdr_body : content_length=0 1(30934) DEBUG: <core> [parser/msg_parser.c:101]: found end of header 1(30934) DEBUG: rr [loose.c:257]: No next Route HF found 1(30934) DEBUG: rr [loose.c:800]: No next URI found 1(30934) DEBUG: rr [rr_cb.c:97]: callback id 0 entered with <lr=on;did=ad4.5f3b1a65> 1(30934) DEBUG: dialog [dlg_handlers.c:787]: route param is 'ad4.5f3b1a65' (len=12) 1(30934) DEBUG: dialog [dlg_hash.c:374]: ref dlg 0xb590ff38 with 1 -> 2 1(30934) DEBUG: dialog [dlg_hash.c:376]: dialog id=1453437941 found on entry 1242 1(30934) DEBUG: <core> [parser/parse_to.c:174]: DEBUG: add_param: tag=3876329704-3958320-1259324882934 1(30934) DEBUG: <core> [parser/parse_to.c:781]: end of header reached, state=29 1(30934) DEBUG: dialog [dlg_hash.c:734]: dialog 0xb590ff38 changed from state 4 to state 5, due event 7 1(30934) DEBUG: dialog [dlg_handlers.c:873]: BYE successfully processed 1(30934) DEBUG: dialog [dlg_hash.c:565]: unref dlg 0xb590ff38 with 2 -> 0 1(30934) DEBUG: dialog [dlg_hash.c:565]: ref <=0 for dialog 0xb590ff38 1(30934) DEBUG: dialog [dlg_hash.c:135]: destroing dialog 0xb590ff38 1(30934) DEBUG: dialog [dlg_hash.c:151]: removed timer for dlg 0xb590ff38 [1242:1453437941] with clid '3569445337-3958280-1259324882918@10.16.48.60' and tags '1718402625-3958280-1259324882918' '3876329704-3958320-1259324882934' 1(30934) DEBUG: tm [t_lookup.c:1387]: DEBUG: t_newtran: msg id=6 , global msg id=5 , T on entrance=(nil) 1(30934) DEBUG: tm [t_lookup.c:528]: t_lookup_request: start searching: hash=62717, isACK=0 1(30934) DEBUG: tm [t_lookup.c:485]: DEBUG: RFC3261 transaction matching failed 1(30934) DEBUG: tm [t_lookup.c:711]: DEBUG: t_lookup_request: no transaction found 1(30934) DEBUG: tm [t_hooks.c:335]: DBG: trans=0xb590f2b8, callback type 1, id 0 entered 1(30934) DEBUG: tm [t_hooks.c:335]: DBG: trans=0xb590f2b8, callback type 1, id 0 entered 1(30934) DEBUG: <core> [msg_translator.c:207]: check_via_address(10.16.48.60, 10.16.48.60, 0) 1(30934) DEBUG: tm [t_funcs.c:386]: SER: new transaction fwd'ed 1(30934) DEBUG: dialog [dlg_hash.c:565]: unref dlg 0xb590ff38 with 1 -> -1 1(30934) CRITICAL: dialog [dlg_hash.c:565]: bogus ref -1 with cnt 1 for dlg 0xb590ff38 [1242:1453437941] with clid '3569445337-3958280-1259324882918@10.16.48.60' and tags '1718402625-3958280-1259324882918' '3876329704-3958320-1259324882934' 1(30934) DEBUG: dialog [dlg_hash.c:565]: ref <=0 for dialog 0xb590ff38 1(30934) DEBUG: dialog [dlg_hash.c:135]: destroing dialog 0xb590ff38 1(30934) DEBUG: dialog [dlg_hash.c:151]: removed timer for dlg 0xb590ff38 [1242:1453437941] with clid '3569445337-3958280-1259324882918@10.16.48.60' and tags '1718402625-3958280-1259324882918' '3876329704-3958320-1259324882934' 1(30934) : <core> [mem/q_malloc.c:446]: BUG: qm_free: freeing already freed pointer, first free: dialog: dlg_hash.c: destroy_dlg(163) - aborting 0(30933) ALERT: <core> [main.c:729]: child process 30934 exited by a signal 6 0(30933) ALERT: <core> [main.c:732]: core was generated 0(30933) INFO: <core> [main.c:744]: INFO: terminating due to SIGCHLD 5(30938) INFO: <core> [main.c:795]: INFO: signal 15 received 4(30937) INFO: <core> [main.c:795]: INFO: signal 15 received 3(30936) INFO: <core> [main.c:795]: INFO: signal 15 received 2(30935) INFO: <core> [main.c:795]: INFO: signal 15 received 0(30933) DEBUG: presence_xml [presence_xml.c:332]: start 0(30933) DEBUG: <core> [db_pool.c:102]: removing connection from the pool 0(30933) DEBUG: tm [t_funcs.c:120]: DEBUG: tm_shutdown : start 0(30933) DEBUG: tm [t_funcs.c:123]: DEBUG: tm_shutdown : emptying hash table 0(30933) DEBUG: tm [t_funcs.c:125]: DEBUG: tm_shutdown : removing semaphores 0(30933) DEBUG: tm [t_funcs.c:127]: DEBUG: tm_shutdown : destroying tmcb lists 0(30933) DEBUG: tm [t_funcs.c:130]: DEBUG: tm_shutdown : done 0(30933) DEBUG: <core> [mem/shm_mem.c:236]: shm_mem_destroy 0(30933) DEBUG: <core> [mem/shm_mem.c:239]: destroying the shared memory lock 0(30933) DEBUG: <core> [main.c:748]: terminating due to SIGCHLD #######################################################################
I hope this information helps solving the problem with the dialog module. I will follow up with testing the presence/dialog-state notifications only when the dialog module itself will work fine. There seems to be another problem in these modules.....
regards,
Klaus
-------- Original-Nachricht --------
Datum: Wed, 25 Nov 2009 18:25:26 +0100 Von: Daniel-Constantin Mierla miconda@gmail.com An: klaus.feichtinger@gmx.net CC: sr-users@lists.sip-router.org Betreff: Re: [SR-Users] Problems with PRESENCE/DIALOG functionality in sip-router
Hello,
can you get the latest git. I just did a fix, I haven't tested the dialoginfo presence module yet, the problem was in some checks in tm.
However, not sure the crash was related. Can you send the backtrace?
gdb /path/to/kamailio core
then: bt
Cheers, Daniel
On 25.11.2009 8:42 Uhr, klaus.feichtinger@gmx.net wrote:
Hi all,
I've tested the current release candidate for Kamailio these days and
found that the presence/dialog state functionality is not given in the current version.
The first (and worst) difference to the latest stable release is that
the handling of "setflag(X)" for tracing the dialogs resulted in a crash of kamailio with following error message:
********************** EXCERPT ****************** Nov 24 13:35:47 lennysrv /usr/local/sbin/kamailio[13814]: : tm
[t_hooks.c:190]: BUG:tm:register_tmcb: callback type TMCB_REQUEST_IN can't be register along with types
Nov 24 13:35:47 lennysrv /usr/local/sbin/kamailio[13814]: ERROR: dialog
[dlg_handlers.c:615]: failed cache in T the shortcut to dlg
Nov 24 13:35:53 lennysrv /usr/local/sbin/kamailio[13815]: NOTICE: acc
[acc.c:275]: ACC: call missed: timestamp=1259134133;method=INVITE;from_tag=4051501197-3958320-1259134127622;to_tag=3762694574-3958280-1259134127622;call_id=140363298-3958320-1259134127622@10.16.48.60;code=603;reason=Decline;src_user=5003;src_domain=10.16.48.205;dst_ouser=5002;dst_user=5002;dst_domain=10.16.48.60
Nov 24 13:35:56 lennysrv /usr/local/sbin/kamailio[13815]: INFO:
pua_usrloc [ul_publish.c:203]: should not send ul publish
Nov 24 13:35:56 lennysrv /usr/local/sbin/kamailio[13815]: INFO:
<script>: --- pua-set-publish() was executed --- > Nov 24 13:35:58 lennysrv kernel: [176699.348059] kamailio[13821]: segfault at c0c0c0c0 ip b7de43b3 sp bfb03eb8 error 5 in libc-2.7.so[b7d6e000+155000] > Nov 24 13:35:58 lennysrv /usr/local/sbin/kamailio[13837]: : <core> [pass_fd.c:283]: ERROR: receive_fd: EOF on 12 > Nov 24 13:35:58 lennysrv /usr/local/sbin/kamailio[13812]: ALERT: <core> [main.c:721]: child process 13821 exited by a signal 11 > Nov 24 13:35:58 lennysrv /usr/local/sbin/kamailio[13812]: ALERT: <core> [main.c:724]: core was generated > Nov 24 13:35:58 lennysrv /usr/local/sbin/kamailio[13812]: INFO: <core> [main.c:736]: INFO: terminating due to SIGCHLD > Nov 24 13:35:58 lennysrv /usr/local/sbin/kamailio[13814]: INFO: <core> [main.c:787]: INFO: signal 15 received > *************************************************** > > However, the module documentation of the source code (READMEs) does not include major news. The configuration is "the same" (regarding handle_publish, handle_subscribe, pua_set_publish) as I've used in the kamailio-1.5.3 version. But - no NOTIFY messages with XML bodies are sent to the subscribers / watchers. Instead of using the setflag(X) method I´ve tried using the method "dlg_setflag(X)" for prohibiting crashes - that was accepted by kamailio. > > Were these modules tested (in combination with the dialog module) in the new version 3.0 RC1? > - presence > - presence_xml > - presence_dialoginfo > - pua > - pua_dialoginfo > - pua_usrloc > > It does not work in the SER variant of sip-router, too. Yesterday I've downloaded the current version with GIT, compiled the code, adapted the configuration. But the result is the same as with kamailio-3 RC1 (crash and no XML). > > For being sure that I have not made any mistake in the configuration, I've tested the functionality in the version 1.5.3 of Kamailio today. It works fine - the subscribers receive NOTIFY messages with XML body after every PRESENCE and DIALOG state change. > > Can anybody give me a hint? Thanks in advance! > > regards, > > Klaus > > > P.S. the tested versions: > > PROBLEMS: > ======== > version: kamailio 3.0.0-rc1 (i386/linux) 78f069 > flags: STATS: Off, USE_IPV6, USE_TCP, USE_TLS, TLS_HOOKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, DBG_QM_MALLOC, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST, HAVE_RESOLV_RES > ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535 > poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. > @(#) $Id$ > main.c compiled on 13:34:37 Nov 20 2009 with gcc 4.3.2 > > > version: ser 2.99.99-pre3 (i386/linux) > flags: STATS: Off, USE_IPV6, USE_TCP, USE_TLS, TLS_HOOKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, DBG_QM_MALLOC, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST, HAVE_RESOLV_RES > ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535 > poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. > @(#) $Id$ > main.c compiled on 11:12:49 Nov 23 2009 with gcc 4.3.2 > > SUCCESS: > ======= > version: kamailio 1.5.3-notls (i386/linux) > flags: STATISTICS, USE_IPV6, USE_TCP, DISABLE_NAGLE, USE_MCAST, SHM_MMAP, PKG_MALLOC, F_MALLOC, FAST_LOCK-ADAPTIVE_WAIT > ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535, PKG_SIZE 4194304 > poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. > svnrevision: unknown > @(#) $Id: main.c 5608 2009-02-13 16:48:17Z henningw $ > main.c compiled on 13:31:21 Nov 24 2009 with gcc 4.3.2 > > -- Daniel-Constantin Mierla * http://www.asipto.com/
Hello,
what I expressed in my previous email, didn't seem related. Hopefully, thanks to your debug info, I was able to find and fix it. Please get the kamailio_3.0 branch from git and test again.
http://www.kamailio.org/dokuwiki/doku.php/install:kamailio-3.0.x-from-git
Thanks, Daniel
On 27.11.2009 13:41 Uhr, Klaus Feichtinger wrote:
Hello,
today I've tested the current version of sip-router (version: ser 2.99.99-pre3 (i386/linux) 470d30) again with the dialog module. I found that the problem is independent of presence/dialog-state information based on subscribe/notify. As soon as the dialog module and the setflag() function for the dlg_flag is used, the server seems to have problems with the BYE message / closing the dialog.
I've done debugging with dbg and the backtrace of the tool is as follows:
(gdb) bt #0 0xb7f1d424 in __kernel_vsyscall () #1 0xb7dcd640 in raise () from /lib/i686/cmov/libc.so.6 #2 0xb7dcf018 in abort () from /lib/i686/cmov/libc.so.6 #3 0x08153dae in qm_free (qm=0xb5773000, p=0xb5910068, file=0xb794b759 "dialog: dlg_hash.c", func=0xb794c035 "destroy_dlg", line=163) at mem/q_malloc.c:447 #4 0xb7934549 in destroy_dlg (dlg=0xb590ff38) at dlg_hash.c:163 #5 0xb7936769 in unref_dlg (dlg=0xb590ff38, cnt=1) at dlg_hash.c:565 #6 0xb793b21d in profile_cleanup (msg=0x82c9d8c, flags=2147483649, param=0x0) at dlg_profile.c:307 #7 0x080e9668 in exec_post_script_cb (msg=0x82c9d8c, type=REQUEST_CB_TYPE) at script_cb.c:195 #8 0x080c5228 in receive_msg ( buf=0x8258940 "BYE sip:5002@10.16.48.60:5071 SIP/2.0\r\nVia: SIP/2.0/UDP 10.16.48.60:5072;rport;branch=z9hG4bK2740720758\r\nRoute: sip:10.16.48.205;lr=on;did=ad4.5f3b1a65\r\nFrom: sip:5003@10.16.48.205;tag=3876329704-"..., len=463, rcv_info=0xbfd38bd8) at receive.c:211 #9 0x08145bc3 in udp_rcv_loop () at udp_server.c:527 #10 0x080997a7 in main_loop () at main.c:1454 #11 0x0809c56b in main (argc=3, argv=0xbfd38e64) at main.c:2251 (gdb)
The original server error messages were:
####################################################################### 1(30934) DEBUG: <core> [forward.c:517]: orig. len=462, new_len=457, proto=1 1(30934) DEBUG: dialog [dlg_hash.c:565]: unref dlg 0xb590ff38 with 1 -> 2 1(30934) DEBUG: <core> [usr_avp.c:636]: DEBUG:destroy_avp_list: destroying list (nil) 1(30934) DEBUG: <core> [usr_avp.c:636]: DEBUG:destroy_avp_list: destroying list (nil) 1(30934) DEBUG: <core> [usr_avp.c:636]: DEBUG:destroy_avp_list: destroying list (nil) 1(30934) DEBUG: <core> [usr_avp.c:636]: DEBUG:destroy_avp_list: destroying list (nil) 1(30934) DEBUG: <core> [usr_avp.c:636]: DEBUG:destroy_avp_list: destroying list (nil) 1(30934) DEBUG: <core> [usr_avp.c:636]: DEBUG:destroy_avp_list: destroying list (nil) 1(30934) DEBUG: <core> [receive.c:267]: receive_msg: cleaning up 3(30936) DEBUG: dialog [dlg_hash.c:622]: unref dlg 0xb590ff38 with 1 -> 1 3(30936) DEBUG: dialog [dlg_hash.c:734]: dialog 0xb590ff38 changed from state 4 to state 4, due event 1 1(30934) DEBUG: <core> [parser/msg_parser.c:621]: SIP Request: 1(30934) DEBUG: <core> [parser/msg_parser.c:623]: method: <BYE> 1(30934) DEBUG: <core> [parser/msg_parser.c:625]: uri: sip:5002@10.16.48.60:5071 1(30934) DEBUG: <core> [parser/msg_parser.c:627]: version: <SIP/2.0> 1(30934) DEBUG: <core> [parser/parse_via.c:1287]: Found param type 235, <rport> = <n/a>; state=6 1(30934) DEBUG: <core> [parser/parse_via.c:1287]: Found param type 232, <branch> = <z9hG4bK2740720758>; state=16 1(30934) DEBUG: <core> [parser/parse_via.c:2300]: end of header reached, state=5 1(30934) DEBUG: <core> [parser/msg_parser.c:509]: parse_headers: Via found, flags=2 1(30934) DEBUG: <core> [parser/msg_parser.c:511]: parse_headers: this is the first via 1(30934) DEBUG: <core> [receive.c:140]: After parse_msg... 1(30934) DEBUG: <core> [receive.c:179]: preparing to run routing scripts... 1(30934) DEBUG: <core> [parser/parse_to.c:174]: DEBUG: add_param: tag=1718402625-3958280-1259324882918 1(30934) DEBUG: <core> [parser/parse_to.c:781]: end of header reached, state=29 1(30934) DEBUG: <core> [parser/msg_parser.c:185]: DEBUG: get_hdr_field: <To> [67]; uri=[sip:5002@10.16.48.205] 1(30934) DEBUG: <core> [parser/msg_parser.c:187]: DEBUG: to body [test sip:5002@10.16.48.205] 1(30934) DEBUG: <core> [parser/msg_parser.c:165]: get_hdr_field: cseq <CSeq>: <21> <BYE> 1(30934) DEBUG: maxfwd [mf_funcs.c:85]: value = 70 1(30934) DEBUG: siputils [checks.c:76]: totag found 1(30934) DEBUG: rr [loose.c:85]: is_preloaded: No 1(30934) DEBUG: <core> [socket_info.c:491]: grep_sock_info - checking if host==us: 11==12 && [10.16.48.60] == [10.16.48.205] 1(30934) DEBUG: <core> [socket_info.c:494]: grep_sock_info - checking if port 5060 matches port 5071 1(30934) DEBUG: <core> [forward.c:362]: check_self: host != me 1(30934) DEBUG: <core> [socket_info.c:491]: grep_sock_info - checking if host==us: 12==12 && [10.16.48.205] == [10.16.48.205] 1(30934) DEBUG: <core> [socket_info.c:494]: grep_sock_info - checking if port 5060 matches port 5060 1(30934) DEBUG: rr [loose.c:781]: Topmost route URI: 'sip:10.16.48.205;lr=on;did=ad4.5f3b1a65' is me 1(30934) DEBUG: <core> [parser/msg_parser.c:199]: DEBUG: get_hdr_body : content_length=0 1(30934) DEBUG: <core> [parser/msg_parser.c:101]: found end of header 1(30934) DEBUG: rr [loose.c:257]: No next Route HF found 1(30934) DEBUG: rr [loose.c:800]: No next URI found 1(30934) DEBUG: rr [rr_cb.c:97]: callback id 0 entered with <lr=on;did=ad4.5f3b1a65> 1(30934) DEBUG: dialog [dlg_handlers.c:787]: route param is 'ad4.5f3b1a65' (len=12) 1(30934) DEBUG: dialog [dlg_hash.c:374]: ref dlg 0xb590ff38 with 1 -> 2 1(30934) DEBUG: dialog [dlg_hash.c:376]: dialog id=1453437941 found on entry 1242 1(30934) DEBUG: <core> [parser/parse_to.c:174]: DEBUG: add_param: tag=3876329704-3958320-1259324882934 1(30934) DEBUG: <core> [parser/parse_to.c:781]: end of header reached, state=29 1(30934) DEBUG: dialog [dlg_hash.c:734]: dialog 0xb590ff38 changed from state 4 to state 5, due event 7 1(30934) DEBUG: dialog [dlg_handlers.c:873]: BYE successfully processed 1(30934) DEBUG: dialog [dlg_hash.c:565]: unref dlg 0xb590ff38 with 2 -> 0 1(30934) DEBUG: dialog [dlg_hash.c:565]: ref <=0 for dialog 0xb590ff38 1(30934) DEBUG: dialog [dlg_hash.c:135]: destroing dialog 0xb590ff38 1(30934) DEBUG: dialog [dlg_hash.c:151]: removed timer for dlg 0xb590ff38 [1242:1453437941] with clid '3569445337-3958280-1259324882918@10.16.48.60' and tags '1718402625-3958280-1259324882918' '3876329704-3958320-1259324882934' 1(30934) DEBUG: tm [t_lookup.c:1387]: DEBUG: t_newtran: msg id=6 , global msg id=5 , T on entrance=(nil) 1(30934) DEBUG: tm [t_lookup.c:528]: t_lookup_request: start searching: hash=62717, isACK=0 1(30934) DEBUG: tm [t_lookup.c:485]: DEBUG: RFC3261 transaction matching failed 1(30934) DEBUG: tm [t_lookup.c:711]: DEBUG: t_lookup_request: no transaction found 1(30934) DEBUG: tm [t_hooks.c:335]: DBG: trans=0xb590f2b8, callback type 1, id 0 entered 1(30934) DEBUG: tm [t_hooks.c:335]: DBG: trans=0xb590f2b8, callback type 1, id 0 entered 1(30934) DEBUG: <core> [msg_translator.c:207]: check_via_address(10.16.48.60, 10.16.48.60, 0) 1(30934) DEBUG: tm [t_funcs.c:386]: SER: new transaction fwd'ed 1(30934) DEBUG: dialog [dlg_hash.c:565]: unref dlg 0xb590ff38 with 1 -> -1 1(30934) CRITICAL: dialog [dlg_hash.c:565]: bogus ref -1 with cnt 1 for dlg 0xb590ff38 [1242:1453437941] with clid '3569445337-3958280-1259324882918@10.16.48.60' and tags '1718402625-3958280-1259324882918' '3876329704-3958320-1259324882934' 1(30934) DEBUG: dialog [dlg_hash.c:565]: ref <=0 for dialog 0xb590ff38 1(30934) DEBUG: dialog [dlg_hash.c:135]: destroing dialog 0xb590ff38 1(30934) DEBUG: dialog [dlg_hash.c:151]: removed timer for dlg 0xb590ff38 [1242:1453437941] with clid '3569445337-3958280-1259324882918@10.16.48.60' and tags '1718402625-3958280-1259324882918' '3876329704-3958320-1259324882934' 1(30934) : <core> [mem/q_malloc.c:446]: BUG: qm_free: freeing already freed pointer, first free: dialog: dlg_hash.c: destroy_dlg(163) - aborting 0(30933) ALERT: <core> [main.c:729]: child process 30934 exited by a signal 6 0(30933) ALERT: <core> [main.c:732]: core was generated 0(30933) INFO: <core> [main.c:744]: INFO: terminating due to SIGCHLD 5(30938) INFO: <core> [main.c:795]: INFO: signal 15 received 4(30937) INFO: <core> [main.c:795]: INFO: signal 15 received 3(30936) INFO: <core> [main.c:795]: INFO: signal 15 received 2(30935) INFO: <core> [main.c:795]: INFO: signal 15 received 0(30933) DEBUG: presence_xml [presence_xml.c:332]: start 0(30933) DEBUG: <core> [db_pool.c:102]: removing connection from the pool 0(30933) DEBUG: tm [t_funcs.c:120]: DEBUG: tm_shutdown : start 0(30933) DEBUG: tm [t_funcs.c:123]: DEBUG: tm_shutdown : emptying hash table 0(30933) DEBUG: tm [t_funcs.c:125]: DEBUG: tm_shutdown : removing semaphores 0(30933) DEBUG: tm [t_funcs.c:127]: DEBUG: tm_shutdown : destroying tmcb lists 0(30933) DEBUG: tm [t_funcs.c:130]: DEBUG: tm_shutdown : done 0(30933) DEBUG: <core> [mem/shm_mem.c:236]: shm_mem_destroy 0(30933) DEBUG: <core> [mem/shm_mem.c:239]: destroying the shared memory lock 0(30933) DEBUG: <core> [main.c:748]: terminating due to SIGCHLD #######################################################################
I hope this information helps solving the problem with the dialog module. I will follow up with testing the presence/dialog-state notifications only when the dialog module itself will work fine. There seems to be another problem in these modules.....
regards,
Klaus
-------- Original-Nachricht --------
Datum: Wed, 25 Nov 2009 18:25:26 +0100 Von: Daniel-Constantin Mierla miconda@gmail.com An: klaus.feichtinger@gmx.net CC: sr-users@lists.sip-router.org Betreff: Re: [SR-Users] Problems with PRESENCE/DIALOG functionality in sip-router
Hello,
can you get the latest git. I just did a fix, I haven't tested the dialoginfo presence module yet, the problem was in some checks in tm.
However, not sure the crash was related. Can you send the backtrace?
gdb /path/to/kamailio core
then: bt
Cheers, Daniel
On 25.11.2009 8:42 Uhr, klaus.feichtinger@gmx.net wrote:
Hi all,
I've tested the current release candidate for Kamailio these days and
found that the presence/dialog state functionality is not given in the current version.
The first (and worst) difference to the latest stable release is that
the handling of "setflag(X)" for tracing the dialogs resulted in a crash of kamailio with following error message:
********************** EXCERPT ****************** Nov 24 13:35:47 lennysrv /usr/local/sbin/kamailio[13814]: : tm
[t_hooks.c:190]: BUG:tm:register_tmcb: callback type TMCB_REQUEST_IN can't be register along with types
Nov 24 13:35:47 lennysrv /usr/local/sbin/kamailio[13814]: ERROR: dialog
[dlg_handlers.c:615]: failed cache in T the shortcut to dlg
Nov 24 13:35:53 lennysrv /usr/local/sbin/kamailio[13815]: NOTICE: acc
[acc.c:275]: ACC: call missed: timestamp=1259134133;method=INVITE;from_tag=4051501197-3958320-1259134127622;to_tag=3762694574-3958280-1259134127622;call_id=140363298-3958320-1259134127622@10.16.48.60;code=603;reason=Decline;src_user=5003;src_domain=10.16.48.205;dst_ouser=5002;dst_user=5002;dst_domain=10.16.48.60
Nov 24 13:35:56 lennysrv /usr/local/sbin/kamailio[13815]: INFO:
pua_usrloc [ul_publish.c:203]: should not send ul publish
Nov 24 13:35:56 lennysrv /usr/local/sbin/kamailio[13815]: INFO:
<script>: --- pua-set-publish() was executed --- > Nov 24 13:35:58 lennysrv kernel: [176699.348059] kamailio[13821]: > segfault at c0c0c0c0 ip b7de43b3 sp bfb03eb8 error 5 in libc-2.7.so[b7d6e000+155000] > Nov 24 13:35:58 lennysrv /usr/local/sbin/kamailio[13837]: : <core> > [pass_fd.c:283]: ERROR: receive_fd: EOF on 12 > Nov 24 13:35:58 lennysrv /usr/local/sbin/kamailio[13812]: ALERT: <core> > [main.c:721]: child process 13821 exited by a signal 11 > Nov 24 13:35:58 lennysrv /usr/local/sbin/kamailio[13812]: ALERT: <core> > [main.c:724]: core was generated > Nov 24 13:35:58 lennysrv /usr/local/sbin/kamailio[13812]: INFO: <core> > [main.c:736]: INFO: terminating due to SIGCHLD > Nov 24 13:35:58 lennysrv /usr/local/sbin/kamailio[13814]: INFO: <core> > [main.c:787]: INFO: signal 15 received > *************************************************** > > However, the module documentation of the source code (READMEs) does not > include major news. The configuration is "the same" (regarding handle_publish, handle_subscribe, pua_set_publish) as I've used in the kamailio-1.5.3 version. But - no NOTIFY messages with XML bodies are sent to the subscribers / watchers. Instead of using the setflag(X) method I´ve tried using the method "dlg_setflag(X)" for prohibiting crashes - that was accepted by kamailio. > Were these modules tested (in combination with the dialog module) in the > new version 3.0 RC1? > - presence > - presence_xml > - presence_dialoginfo > - pua > - pua_dialoginfo > - pua_usrloc > > It does not work in the SER variant of sip-router, too. Yesterday I've > downloaded the current version with GIT, compiled the code, adapted the configuration. But the result is the same as with kamailio-3 RC1 (crash and no XML). > For being sure that I have not made any mistake in the configuration, > I've tested the functionality in the version 1.5.3 of Kamailio today. It works fine - the subscribers receive NOTIFY messages with XML body after every PRESENCE and DIALOG state change. > Can anybody give me a hint? Thanks in advance! > > regards, > > Klaus > > > P.S. the tested versions: > > PROBLEMS: > ======== > version: kamailio 3.0.0-rc1 (i386/linux) 78f069 > flags: STATS: Off, USE_IPV6, USE_TCP, USE_TLS, TLS_HOOKS, DISABLE_NAGLE, > USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, DBG_QM_MALLOC, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST, HAVE_RESOLV_RES > ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, > MAX_URI_SIZE 1024, BUF_SIZE 65535 > poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. > @(#) $Id$ > main.c compiled on 13:34:37 Nov 20 2009 with gcc 4.3.2 > > > version: ser 2.99.99-pre3 (i386/linux) > flags: STATS: Off, USE_IPV6, USE_TCP, USE_TLS, TLS_HOOKS, DISABLE_NAGLE, > USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, DBG_QM_MALLOC, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST, HAVE_RESOLV_RES > ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, > MAX_URI_SIZE 1024, BUF_SIZE 65535 > poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. > @(#) $Id$ > main.c compiled on 11:12:49 Nov 23 2009 with gcc 4.3.2 > > SUCCESS: > ======= > version: kamailio 1.5.3-notls (i386/linux) > flags: STATISTICS, USE_IPV6, USE_TCP, DISABLE_NAGLE, USE_MCAST, > SHM_MMAP, PKG_MALLOC, F_MALLOC, FAST_LOCK-ADAPTIVE_WAIT > ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, > MAX_URI_SIZE 1024, BUF_SIZE 65535, PKG_SIZE 4194304 > poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. > svnrevision: unknown > @(#) $Id: main.c 5608 2009-02-13 16:48:17Z henningw $ > main.c compiled on 13:31:21 Nov 24 2009 with gcc 4.3.2 > > > -- Daniel-Constantin Mierla * http://www.asipto.com/
Hello,
with this "last" version the fault with the dialog flag is solved. I've tested with this version: "version: kamailio 3.0.0-rc2 (i386/linux) 9dca82"
However, the problem with presence/dialog-state notification is still open. I will make ongoing tests next week.
Thx for the fix!
regards,
Klaus -------- Original-Nachricht --------
Datum: Fri, 27 Nov 2009 14:58:39 +0100 Von: Daniel-Constantin Mierla miconda@gmail.com An: Klaus Feichtinger klaus.feichtinger@gmx.net CC: sr-users@lists.sip-router.org Betreff: Re: [SR-Users] Problems with PRESENCE/DIALOG functionality in sip-router
Hello,
what I expressed in my previous email, didn't seem related. Hopefully, thanks to your debug info, I was able to find and fix it. Please get the kamailio_3.0 branch from git and test again.
http://www.kamailio.org/dokuwiki/doku.php/install:kamailio-3.0.x-from-git
Thanks, Daniel
On 27.11.2009 13:41 Uhr, Klaus Feichtinger wrote:
Hello,
today I've tested the current version of sip-router (version: ser
2.99.99-pre3 (i386/linux) 470d30) again with the dialog module. I found that the problem is independent of presence/dialog-state information based on subscribe/notify. As soon as the dialog module and the setflag() function for the dlg_flag is used, the server seems to have problems with the BYE message / closing the dialog.
I've done debugging with dbg and the backtrace of the tool is as
follows:
(gdb) bt #0 0xb7f1d424 in __kernel_vsyscall () #1 0xb7dcd640 in raise () from /lib/i686/cmov/libc.so.6 #2 0xb7dcf018 in abort () from /lib/i686/cmov/libc.so.6 #3 0x08153dae in qm_free (qm=0xb5773000, p=0xb5910068, file=0xb794b759
"dialog: dlg_hash.c", func=0xb794c035 "destroy_dlg", line=163) at mem/q_malloc.c:447
#4 0xb7934549 in destroy_dlg (dlg=0xb590ff38) at dlg_hash.c:163 #5 0xb7936769 in unref_dlg (dlg=0xb590ff38, cnt=1) at dlg_hash.c:565 #6 0xb793b21d in profile_cleanup (msg=0x82c9d8c, flags=2147483649,
param=0x0) at dlg_profile.c:307
#7 0x080e9668 in exec_post_script_cb (msg=0x82c9d8c,
type=REQUEST_CB_TYPE) at script_cb.c:195
#8 0x080c5228 in receive_msg ( buf=0x8258940 "BYE sip:5002@10.16.48.60:5071 SIP/2.0\r\nVia:
SIP/2.0/UDP 10.16.48.60:5072;rport;branch=z9hG4bK2740720758\r\nRoute: sip:10.16.48.205;lr=on;did=ad4.5f3b1a65\r\nFrom: sip:5003@10.16.48.205;tag=3876329704-"..., len=463, rcv_info=0xbfd38bd8) at receive.c:211
#9 0x08145bc3 in udp_rcv_loop () at udp_server.c:527 #10 0x080997a7 in main_loop () at main.c:1454 #11 0x0809c56b in main (argc=3, argv=0xbfd38e64) at main.c:2251 (gdb)
The original server error messages were:
####################################################################### 1(30934) DEBUG: <core> [forward.c:517]: orig. len=462, new_len=457,
proto=1
1(30934) DEBUG: dialog [dlg_hash.c:565]: unref dlg 0xb590ff38 with 1 ->
2
1(30934) DEBUG: <core> [usr_avp.c:636]: DEBUG:destroy_avp_list:
destroying list (nil)
1(30934) DEBUG: <core> [usr_avp.c:636]: DEBUG:destroy_avp_list:
destroying list (nil)
1(30934) DEBUG: <core> [usr_avp.c:636]: DEBUG:destroy_avp_list:
destroying list (nil)
1(30934) DEBUG: <core> [usr_avp.c:636]: DEBUG:destroy_avp_list:
destroying list (nil)
1(30934) DEBUG: <core> [usr_avp.c:636]: DEBUG:destroy_avp_list:
destroying list (nil)
1(30934) DEBUG: <core> [usr_avp.c:636]: DEBUG:destroy_avp_list:
destroying list (nil)
1(30934) DEBUG: <core> [receive.c:267]: receive_msg: cleaning up 3(30936) DEBUG: dialog [dlg_hash.c:622]: unref dlg 0xb590ff38 with 1 ->
1
3(30936) DEBUG: dialog [dlg_hash.c:734]: dialog 0xb590ff38 changed from
state 4 to state 4, due event 1
1(30934) DEBUG: <core> [parser/msg_parser.c:621]: SIP Request: 1(30934) DEBUG: <core> [parser/msg_parser.c:623]: method: <BYE> 1(30934) DEBUG: <core> [parser/msg_parser.c:625]: uri:
1(30934) DEBUG: <core> [parser/msg_parser.c:627]: version: <SIP/2.0> 1(30934) DEBUG: <core> [parser/parse_via.c:1287]: Found param type 235,
<rport> = <n/a>; state=6
1(30934) DEBUG: <core> [parser/parse_via.c:1287]: Found param type 232,
<branch> = <z9hG4bK2740720758>; state=16
1(30934) DEBUG: <core> [parser/parse_via.c:2300]: end of header
reached, state=5
1(30934) DEBUG: <core> [parser/msg_parser.c:509]: parse_headers: Via
found, flags=2
1(30934) DEBUG: <core> [parser/msg_parser.c:511]: parse_headers: this
is the first via
1(30934) DEBUG: <core> [receive.c:140]: After parse_msg... 1(30934) DEBUG: <core> [receive.c:179]: preparing to run routing
scripts...
1(30934) DEBUG: <core> [parser/parse_to.c:174]: DEBUG: add_param:
tag=1718402625-3958280-1259324882918
1(30934) DEBUG: <core> [parser/parse_to.c:781]: end of header reached,
state=29
1(30934) DEBUG: <core> [parser/msg_parser.c:185]: DEBUG: get_hdr_field:
<To> [67]; uri=[sip:5002@10.16.48.205]
1(30934) DEBUG: <core> [parser/msg_parser.c:187]: DEBUG: to body [test
1(30934) DEBUG: <core> [parser/msg_parser.c:165]: get_hdr_field: cseq
<CSeq>: <21> <BYE>
1(30934) DEBUG: maxfwd [mf_funcs.c:85]: value = 70 1(30934) DEBUG: siputils [checks.c:76]: totag found 1(30934) DEBUG: rr [loose.c:85]: is_preloaded: No 1(30934) DEBUG: <core> [socket_info.c:491]: grep_sock_info - checking
if host==us: 11==12 && [10.16.48.60] == [10.16.48.205]
1(30934) DEBUG: <core> [socket_info.c:494]: grep_sock_info - checking
if port 5060 matches port 5071
1(30934) DEBUG: <core> [forward.c:362]: check_self: host != me 1(30934) DEBUG: <core> [socket_info.c:491]: grep_sock_info - checking
if host==us: 12==12 && [10.16.48.205] == [10.16.48.205]
1(30934) DEBUG: <core> [socket_info.c:494]: grep_sock_info - checking
if port 5060 matches port 5060
1(30934) DEBUG: rr [loose.c:781]: Topmost route URI:
'sip:10.16.48.205;lr=on;did=ad4.5f3b1a65' is me
1(30934) DEBUG: <core> [parser/msg_parser.c:199]: DEBUG: get_hdr_body :
content_length=0
1(30934) DEBUG: <core> [parser/msg_parser.c:101]: found end of header 1(30934) DEBUG: rr [loose.c:257]: No next Route HF found 1(30934) DEBUG: rr [loose.c:800]: No next URI found 1(30934) DEBUG: rr [rr_cb.c:97]: callback id 0 entered with
<lr=on;did=ad4.5f3b1a65>
1(30934) DEBUG: dialog [dlg_handlers.c:787]: route param is
'ad4.5f3b1a65' (len=12)
1(30934) DEBUG: dialog [dlg_hash.c:374]: ref dlg 0xb590ff38 with 1 -> 2 1(30934) DEBUG: dialog [dlg_hash.c:376]: dialog id=1453437941 found on
entry 1242
1(30934) DEBUG: <core> [parser/parse_to.c:174]: DEBUG: add_param:
tag=3876329704-3958320-1259324882934
1(30934) DEBUG: <core> [parser/parse_to.c:781]: end of header reached,
state=29
1(30934) DEBUG: dialog [dlg_hash.c:734]: dialog 0xb590ff38 changed from
state 4 to state 5, due event 7
1(30934) DEBUG: dialog [dlg_handlers.c:873]: BYE successfully processed 1(30934) DEBUG: dialog [dlg_hash.c:565]: unref dlg 0xb590ff38 with 2 ->
0
1(30934) DEBUG: dialog [dlg_hash.c:565]: ref <=0 for dialog 0xb590ff38 1(30934) DEBUG: dialog [dlg_hash.c:135]: destroing dialog 0xb590ff38 1(30934) DEBUG: dialog [dlg_hash.c:151]: removed timer for dlg
0xb590ff38 [1242:1453437941] with clid '3569445337-3958280-1259324882918@10.16.48.60' and tags '1718402625-3958280-1259324882918' '3876329704-3958320-1259324882934'
1(30934) DEBUG: tm [t_lookup.c:1387]: DEBUG: t_newtran: msg id=6 ,
global msg id=5 , T on entrance=(nil)
1(30934) DEBUG: tm [t_lookup.c:528]: t_lookup_request: start searching:
hash=62717, isACK=0
1(30934) DEBUG: tm [t_lookup.c:485]: DEBUG: RFC3261 transaction
matching failed
1(30934) DEBUG: tm [t_lookup.c:711]: DEBUG: t_lookup_request: no
transaction found
1(30934) DEBUG: tm [t_hooks.c:335]: DBG: trans=0xb590f2b8, callback
type 1, id 0 entered
1(30934) DEBUG: tm [t_hooks.c:335]: DBG: trans=0xb590f2b8, callback
type 1, id 0 entered
1(30934) DEBUG: <core> [msg_translator.c:207]:
check_via_address(10.16.48.60, 10.16.48.60, 0)
1(30934) DEBUG: tm [t_funcs.c:386]: SER: new transaction fwd'ed 1(30934) DEBUG: dialog [dlg_hash.c:565]: unref dlg 0xb590ff38 with 1 ->
-1
1(30934) CRITICAL: dialog [dlg_hash.c:565]: bogus ref -1 with cnt 1 for
dlg 0xb590ff38 [1242:1453437941] with clid '3569445337-3958280-1259324882918@10.16.48.60' and tags '1718402625-3958280-1259324882918' '3876329704-3958320-1259324882934'
1(30934) DEBUG: dialog [dlg_hash.c:565]: ref <=0 for dialog 0xb590ff38 1(30934) DEBUG: dialog [dlg_hash.c:135]: destroing dialog 0xb590ff38 1(30934) DEBUG: dialog [dlg_hash.c:151]: removed timer for dlg
0xb590ff38 [1242:1453437941] with clid '3569445337-3958280-1259324882918@10.16.48.60' and tags '1718402625-3958280-1259324882918' '3876329704-3958320-1259324882934'
1(30934) : <core> [mem/q_malloc.c:446]: BUG: qm_free: freeing already
freed pointer, first free: dialog: dlg_hash.c: destroy_dlg(163) - aborting
0(30933) ALERT: <core> [main.c:729]: child process 30934 exited by a
signal 6
0(30933) ALERT: <core> [main.c:732]: core was generated 0(30933) INFO: <core> [main.c:744]: INFO: terminating due to SIGCHLD 5(30938) INFO: <core> [main.c:795]: INFO: signal 15 received 4(30937) INFO: <core> [main.c:795]: INFO: signal 15 received 3(30936) INFO: <core> [main.c:795]: INFO: signal 15 received 2(30935) INFO: <core> [main.c:795]: INFO: signal 15 received 0(30933) DEBUG: presence_xml [presence_xml.c:332]: start 0(30933) DEBUG: <core> [db_pool.c:102]: removing connection from the
pool
0(30933) DEBUG: tm [t_funcs.c:120]: DEBUG: tm_shutdown : start 0(30933) DEBUG: tm [t_funcs.c:123]: DEBUG: tm_shutdown : emptying hash
table
0(30933) DEBUG: tm [t_funcs.c:125]: DEBUG: tm_shutdown : removing
semaphores
0(30933) DEBUG: tm [t_funcs.c:127]: DEBUG: tm_shutdown : destroying
tmcb lists
0(30933) DEBUG: tm [t_funcs.c:130]: DEBUG: tm_shutdown : done 0(30933) DEBUG: <core> [mem/shm_mem.c:236]: shm_mem_destroy 0(30933) DEBUG: <core> [mem/shm_mem.c:239]: destroying the shared
memory lock
0(30933) DEBUG: <core> [main.c:748]: terminating due to SIGCHLD #######################################################################
I hope this information helps solving the problem with the dialog
module. I will follow up with testing the presence/dialog-state notifications only when the dialog module itself will work fine. There seems to be another problem in these modules.....
regards,
Klaus
-------- Original-Nachricht --------
Datum: Wed, 25 Nov 2009 18:25:26 +0100 Von: Daniel-Constantin Mierla miconda@gmail.com An: klaus.feichtinger@gmx.net CC: sr-users@lists.sip-router.org Betreff: Re: [SR-Users] Problems with PRESENCE/DIALOG functionality in
sip-router
Hello,
can you get the latest git. I just did a fix, I haven't tested the dialoginfo presence module yet, the problem was in some checks in tm.
However, not sure the crash was related. Can you send the backtrace?
gdb /path/to/kamailio core
then: bt
Cheers, Daniel
On 25.11.2009 8:42 Uhr, klaus.feichtinger@gmx.net wrote:
Hi all,
I've tested the current release candidate for Kamailio these days and
found that the presence/dialog state functionality is not given in the current version.
The first (and worst) difference to the latest stable release is that
the handling of "setflag(X)" for tracing the dialogs resulted in a
crash of
kamailio with following error message:
********************** EXCERPT ****************** Nov 24 13:35:47 lennysrv /usr/local/sbin/kamailio[13814]: : tm
[t_hooks.c:190]: BUG:tm:register_tmcb: callback type TMCB_REQUEST_IN
can't be
register along with types
Nov 24 13:35:47 lennysrv /usr/local/sbin/kamailio[13814]: ERROR:
dialog
[dlg_handlers.c:615]: failed cache in T the shortcut to dlg
Nov 24 13:35:53 lennysrv /usr/local/sbin/kamailio[13815]: NOTICE: acc
[acc.c:275]: ACC: call missed:
timestamp=1259134133;method=INVITE;from_tag=4051501197-3958320-1259134127622;to_tag=3762694574-3958280-1259134127622;call_id=140363298-3958320-1259134127622@10.16.48.60;code=603;reason=Decline;src_user=5003;src_domain=10.16.48.205;dst_ouser=5002;dst_user=5002;dst_domain=10.16.48.60
Nov 24 13:35:56 lennysrv /usr/local/sbin/kamailio[13815]: INFO:
pua_usrloc [ul_publish.c:203]: should not send ul publish
Nov 24 13:35:56 lennysrv /usr/local/sbin/kamailio[13815]: INFO:
<script>: --- pua-set-publish() was executed --- > Nov 24 13:35:58 lennysrv kernel: [176699.348059] kamailio[13821]: > segfault at c0c0c0c0 ip b7de43b3 sp bfb03eb8 error 5 in libc-2.7.so[b7d6e000+155000] > Nov 24 13:35:58 lennysrv /usr/local/sbin/kamailio[13837]: : <core> > [pass_fd.c:283]: ERROR: receive_fd: EOF on 12 > Nov 24 13:35:58 lennysrv /usr/local/sbin/kamailio[13812]: ALERT:
<core> >>> >> [main.c:721]: child process 13821 exited by a signal 11 >> >>> Nov 24 13:35:58 lennysrv /usr/local/sbin/kamailio[13812]: ALERT: <core> >>> >> [main.c:724]: core was generated >> >>> Nov 24 13:35:58 lennysrv /usr/local/sbin/kamailio[13812]: INFO: <core> >>> >> [main.c:736]: INFO: terminating due to SIGCHLD >> >>> Nov 24 13:35:58 lennysrv /usr/local/sbin/kamailio[13814]: INFO: <core> >>> >> [main.c:787]: INFO: signal 15 received >> >>> *************************************************** >>> >>> However, the module documentation of the source code (READMEs) does not >>> >> include major news. The configuration is "the same" (regarding >> handle_publish, handle_subscribe, pua_set_publish) as I've used in the kamailio-1.5.3 >> version. But - no NOTIFY messages with XML bodies are sent to the >> subscribers / watchers. Instead of using the setflag(X) method I´ve tried using the >> method "dlg_setflag(X)" for prohibiting crashes - that was accepted by >> kamailio. >> >>> Were these modules tested (in combination with the dialog module) in the >>> >> new version 3.0 RC1? >> >>> - presence >>> - presence_xml >>> - presence_dialoginfo >>> - pua >>> - pua_dialoginfo >>> - pua_usrloc >>> >>> It does not work in the SER variant of sip-router, too. Yesterday I've >>> >> downloaded the current version with GIT, compiled the code, adapted the >> configuration. But the result is the same as with kamailio-3 RC1 (crash and no >> XML). >> >>> For being sure that I have not made any mistake in the configuration, >>> >> I've tested the functionality in the version 1.5.3 of Kamailio today. It >> works fine - the subscribers receive NOTIFY messages with XML body after every >> PRESENCE and DIALOG state change. >> >>> Can anybody give me a hint? Thanks in advance! >>> >>> regards, >>> >>> Klaus >>> >>> >>> P.S. the tested versions: >>> >>> PROBLEMS: >>> ======== >>> version: kamailio 3.0.0-rc1 (i386/linux) 78f069 >>> flags: STATS: Off, USE_IPV6, USE_TCP, USE_TLS, TLS_HOOKS, DISABLE_NAGLE, >>> >> USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, DBG_QM_MALLOC, >> USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, >> USE_DST_BLACKLIST, HAVE_RESOLV_RES >> >>> ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, >>> >> MAX_URI_SIZE 1024, BUF_SIZE 65535 >> >>> poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. >>> @(#) $Id$ >>> main.c compiled on 13:34:37 Nov 20 2009 with gcc 4.3.2 >>> >>> >>> version: ser 2.99.99-pre3 (i386/linux) >>> flags: STATS: Off, USE_IPV6, USE_TCP, USE_TLS, TLS_HOOKS, DISABLE_NAGLE, >>> >> USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, DBG_QM_MALLOC, >> USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, >> USE_DST_BLACKLIST, HAVE_RESOLV_RES >> >>> ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, >>> >> MAX_URI_SIZE 1024, BUF_SIZE 65535 >> >>> poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. >>> @(#) $Id$ >>> main.c compiled on 11:12:49 Nov 23 2009 with gcc 4.3.2 >>> >>> SUCCESS: >>> ======= >>> version: kamailio 1.5.3-notls (i386/linux) >>> flags: STATISTICS, USE_IPV6, USE_TCP, DISABLE_NAGLE, USE_MCAST, >>> >> SHM_MMAP, PKG_MALLOC, F_MALLOC, FAST_LOCK-ADAPTIVE_WAIT >> >>> ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, >>> >> MAX_URI_SIZE 1024, BUF_SIZE 65535, PKG_SIZE 4194304 >> >>> poll method support: poll, epoll_lt, epoll_et, sigio_rt, select. >>> svnrevision: unknown >>> @(#) $Id: main.c 5608 2009-02-13 16:48:17Z henningw $ >>> main.c compiled on 13:31:21 Nov 24 2009 with gcc 4.3.2 >>> >>> >>> >> -- >> Daniel-Constantin Mierla >> * http://www.asipto.com/ >> > >
-- Daniel-Constantin Mierla
-
Daniel-Constantin Mierla -
Klaus Feichtinger -
klaus.feichtinger＠gmx.net