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(a)gmail.com>
An: Klaus Feichtinger <klaus.feichtinger(a)gmx.net>
CC: sr-users(a)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:
<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(a)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(a)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(a)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(a)gmail.com>
> An: klaus.feichtinger(a)gmx.net
> CC: sr-users(a)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(a)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(a)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
*
http://www.asipto.com/
--
GRATIS für alle GMX-Mitglieder: Die maxdome Movie-FLAT!
Jetzt freischalten unter