Hello All,
Okay I'm beginning to believe this is a sofia-sip bug (version 1.12.7),
related to the creation/deletion of NUAs. Can anyone take a look at this?
Am I doing something wrong in my application (see CE2S logs below)?
I have a requirement to reconfigure lines on the phone without rebooting it.
The scenario is as follows:
1) Create/Register/Subscribe line 10281
2) Unsubscribe/Unregister/Shutdown/Delete line 10281
3) Create/Register/Subscribe line 10282
4) Unsubscribe/Unregister/Shutdown/Delete line 10281
***********************************************
***** Segmentation Violation When 200 OK *****
***** is received in response to REGISTER *****
***** Expires 0 (i.e. unregister) *****
***********************************************
Best Regards,
Jerry
Detailed trace of NUA calls (CE2S), NUA callbacks (CESC) and sofia-sip
SU_DEBUG_9 (SOFI) logs follows:
----------------------------START OF TRACE--------------------------------
Time Type Summary
00:41.197p CE2S su_init()
00:41.198p CE2S su_home_init(appl->home=0x7474a0)
00:41.199p CE2S ...su_home_init() returned 0x0
00:41.199p CE2S su_root_create(magic=0x0)
00:41.204p CE2S ...su_root_create() returned appl->root=0x7988e0
00:41.206p CE2S su_root_threading(self=0x7988e0, enable=0)
00:41.206p CE2S ...su_root_threading() returned 0x0
00:41.207p CE2S nua_create(root=0x7988e0, callback=0x550d9c,
magic=0x781158, url=sip:192.168.72.151:50001)
00:41.208p SOFI nua: nua_create: entering
00:41.209p SOFI nua: nua_stack_init: entering
00:41.212p SOFI nua: nua_stack_set_params: entering
00:41.213p SOFI soa_create("default", 0x798968, 0x7b0a48) called
00:41.214p SOFI soa_set_params(static::0x7b0e30, ...) called
00:41.216p SOFI nta_agent_create: initialized hash tables
00:41.217p SOFI nta_agent_create: initialized transports
00:41.218p SOFI nta_agent_create: initialized random identifiers
00:41.219p SOFI nta_agent_create: initialized timer
00:41.222p SOFI nta_agent_create: initialized resolver
00:41.224p SOFI tport_create(): 0x7b2110
00:41.225p SOFI nta: master transport created
00:41.226p SOFI tport_bind_server(0x7b2110) to */192.168.72.151:50001/sip
00:41.228p SOFI tport_bind_server(0x7b2110): calling tport_listen for udp
00:41.229p SOFI tport_alloc_primary(0x7b2110): new primary tport 0x7b24e8
00:41.232p SOFI tport_listen(0x7b24e8): listening at
udp/192.168.72.151:50001/sip
00:41.234p SOFI tport_bind_server(0x7b2110): calling tport_listen for tcp
00:41.235p SOFI tport_alloc_primary(0x7b2110): new primary tport 0x7b2788
00:41.237p SOFI tport_listen(0x7b2788): listening at
tcp/192.168.72.151:50001/sip
00:41.238p SOFI nta: bound to (192.168.72.151:50001;transport=*)
00:41.239p SOFI nta: agent_init_via: SIP/2.0/udp 192.168.72.151:50001 (sip)
00:41.241p SOFI nta: agent_init_via: SIP/2.0/tcp 192.168.72.151:50001 (sip)
00:41.242p SOFI nta: Via fields initialized
00:41.244p SOFI nta: Contact header created
00:41.245p SOFI nua_register: Adding contact URL '192.168.72.151' to list.
00:41.246p CE2S ...nua_create() returned
mkData[la].pLine->lineH=0x7b07b0
00:41.440p CE2S nua_set_params(nua=0x7b07b0, NUTAG_ALLOW_EVENTS(dialog))
00:41.442p SOFI nua: nua_set_params: entering
00:41.443p SOFI nua((nil)): signal r_set_params
00:41.444p CE2S nua_set_params(nua=0x7b07b0, NUTAG_ALLOW_EVENTS(sla))
00:41.445p SOFI nua: nua_set_params: entering
00:41.446p SOFI nua((nil)): signal r_set_params
00:41.447p CE2S nua_set_params(nua=0x7b07b0,
NUTAG_ALLOW_EVENTS(include-session-description))
00:41.448p SOFI nua: nua_set_params: entering
00:41.449p SOFI nua((nil)): signal r_set_params
00:41.450p CE2S [2]nua_handle(nua=0x7b07b0, hmagic=0x781158,
url=sip:[EMAIL PROTECTED]:5060)
00:41.451p SOFI nua: nh_create_handle: entering
00:41.453p CE2S ...[2]nua_handle() returned nh=0x7b2f80
00:41.454p CE2S nua_register(nh=0x7b2f80,
SIPTAG_FROM(sip:[EMAIL PROTECTED]:5060),
00:41.455p CE2S NUTAG_M_DISPLAY(), NUTAG_M_USERNAME(10281),
00:41.456p CE2S
NUTAG_M_FEATURES(reg-id=1804289383;+sip.instance="<urn:uuid:c39b0000-4f96-1a
00-1000-00048d0000b8>")
00:41.457p CE2S NUTAG_OUTBOUND(no-validate no-natify
no-options-keepalive))
00:41.458p SOFI nua: nua_register: entering
00:41.459p SOFI nua(0x7b2f80): signal r_register
00:41.461p SOFI nua((nil)): recv r_set_params
00:41.461p SOFI nua((nil)): signal r_set_params
00:41.461p SOFI nua: nua_stack_set_params: entering
00:41.462p SOFI soa_set_params(static::0x7b0e30, ...) called
00:41.462p SOFI nua((nil)): event r_set_params 200 OK
00:41.463p SOFI nua((nil)): recv r_set_params
00:41.463p SOFI nua((nil)): signal r_set_params
00:41.463p SOFI nua: nua_stack_set_params: entering
00:41.463p SOFI soa_set_params(static::0x7b0e30, ...) called
00:41.464p SOFI nua((nil)): event r_set_params 200 OK
00:41.464p SOFI nua((nil)): recv r_set_params
00:41.464p SOFI nua((nil)): signal r_set_params
00:41.465p SOFI nua: nua_stack_set_params: entering
00:41.465p SOFI soa_set_params(static::0x7b0e30, ...) called
00:41.466p SOFI nua((nil)): event r_set_params 200 OK
00:41.466p SOFI nua(0x7b2f80): recv r_register
00:41.466p SOFI nua(0x7b2f80): signal r_register
00:41.466p SOFI nua: nua_stack_set_params: entering
00:41.467p SOFI soa_clone(static::0x7b0e30, 0x798968, 0x7b2f80) called
00:41.467p SOFI soa_set_params(static::0x7b3360, ...) called
00:41.484p SOFI nta_leg_tcreate(0x7b3b70)
00:41.484p SOFI nua(0x7b2f80): adding register usage
00:41.487p SOFI nta: selecting scheme sip
00:41.487p SOFI tport(0x7b24e8): EXPENSIVE unresolved */192.168.72.130:5060
00:41.488p SOFI tport_tsend(0x7b24e8) tpn = */192.168.72.130:5060
00:41.488p SOFI tport_resolve addrinfo = 192.168.72.130:5060
00:41.488p SOFI tport_by_addrinfo(0x7b24e8): not found by name
*/192.168.72.130:5060
00:41.495p SOFI tport_vsend(0x7b24e8): 601 bytes of 601 to
*/192.168.72.130:5060
00:41.496p SOFI tport_vsend returned 601
00:41.497p SOFI nta: sent REGISTER (101441812) to */192.168.72.130:5060
00:41.498p SOFI tport_pend(0x7b24e8): pending 0x7b5448 for
udp/192.168.72.151:50001 (already 0)
00:41.499p SOFI nta: timer set to 32000 ms
00:41.501p SOFI nta: timer shortened to 500 ms
00:41.502p SOFI nua: nua_event: entering
00:41.502p CESC ce_ProcCallback: Rcvd event for nua=0x7b07b0,
pMkData=0x781158, nh=0x0, hmagic=0x0, sip=0x0
00:41.502p CESC nua_r_set_params event: 200 OK
(pMkData->mk=MK1=lineH=0x7b07b0)
00:41.502p CESC Discarding Event...
00:41.502p SOFI nua: nua_event: entering
00:41.502p CESC ce_ProcCallback: Rcvd event for nua=0x7b07b0,
pMkData=0x781158, nh=0x0, hmagic=0x0, sip=0x0
00:41.502p CESC nua_r_set_params event: 200 OK
(pMkData->mk=MK1=lineH=0x7b07b0)
00:41.503p CESC Discarding Event...
00:41.503p SOFI nua: nua_event: entering
00:41.503p CESC ce_ProcCallback: Rcvd event for nua=0x7b07b0,
pMkData=0x781158, nh=0x0, hmagic=0x0, sip=0x0
00:41.503p CESC nua_r_set_params event: 200 OK
(pMkData->mk=MK1=lineH=0x7b07b0)
00:41.503p CESC Discarding Event...
00:41.503p SOFI tport_wakeup_pri(0x7b24e8): events IN
00:41.504p SOFI tport_recv_event(0x7b24e8)
00:41.504p SOFI tport_recv_iovec(0x7b24e8) msg 0x7b6128 from
(udp/192.168.72.151:50001) has 431 bytes, veclen = 1
00:41.506p SOFI tport_deliver(0x7b24e8): msg 0x7b6128 (431 bytes) from
udp/192.168.72.130:50001/sip next=(nil)
00:41.506p SOFI nta: received 100 Trying for REGISTER (101441812)
00:41.506p SOFI nta: 100 Trying is going to a transaction
00:41.507p SOFI nta_outgoing: RTT is 18.752 ms
00:41.507p SOFI tport_release(0x7b24e8): 0x7b5448 by 0x7b5ae8 with 0x7b6128
(preliminary)
00:41.507p SOFI nua(0x7b2f80): event r_register 100 Trying
00:41.508p SOFI nua: nua_event: entering
00:41.508p CESC ce_ProcCallback: Rcvd event for nua=0x7b07b0,
pMkData=0x781158, nh=0x7b2f80, hmagic=0x781158, sip=0x7b61c4
00:41.508p CESC nua_r_register event: 100 Trying
(pMkData->mk=MK1=lineH=0x7b07b0)
00:41.508p CESC Handled Event Locally...
00:41.509p SOFI tport_wakeup_pri(0x7b24e8): events IN
00:41.509p SOFI tport_recv_event(0x7b24e8)
00:41.509p SOFI tport_recv_iovec(0x7b24e8) msg 0x7b6860 from
(udp/192.168.72.151:50001) has 511 bytes, veclen = 1
00:41.523p SOFI tport_deliver(0x7b24e8): msg 0x7b6860 (511 bytes) from
udp/192.168.72.130:50001/sip next=(nil)
00:41.523p SOFI nta: received 200 OK for REGISTER (101441812)
00:41.523p SOFI nta: 200 OK is going to a transaction
00:41.523p SOFI tport_release(0x7b24e8): 0x7b5448 by 0x7b5ae8 with 0x7b6860
00:41.524p SOFI nua(): refresh register after 75 seconds (in [60..90])
00:41.524p SOFI nua(): refresh register after 75 seconds
00:41.525p SOFI nua(0x7b2f80): event r_register 200 OK
00:41.525p SOFI nua: nua_event: entering
00:41.525p CESC ce_ProcCallback: Rcvd event for nua=0x7b07b0,
pMkData=0x781158, nh=0x7b2f80, hmagic=0x781158, sip=0x7b68fc
00:41.525p CESC nua_r_register event: 200 OK
(pMkData->mk=MK1=lineH=0x7b07b0)
00:41.525p CESC Reporting Event S_REGISTERED_EV...
00:41.526p CE2S [2]nua_handle(nua=0x7b07b0, hmagic=0x781158,
url=sip:[EMAIL PROTECTED]:5060)
00:41.526p SOFI nua: nh_create_handle: entering
00:41.527p CE2S ...[2]nua_handle() returned nh=0x7b7200
00:41.527p CE2S nua_subscribe(nh=0x7b7200, NUTAG_M_DISPLAY()
00:41.527p CE2S SIPTAG_FROM(sip:[EMAIL PROTECTED]:5060),
NUTAG_M_USERNAME(10281),
00:41.527p CE2S SIPTAG_EVENT(message-summary),
SIPTAG_ACCEPT(application/simple-message-summary),
00:41.527p CE2S SIPTAG_EXPIRES(3600), NUTAG_OUTBOUND(no-validate
no-natify no-options-keepalive))
00:41.528p SOFI nua: nua_subscribe: entering
00:41.528p SOFI nua(0x7b7200): signal r_subscribe
00:41.600p SOFI nua(0x7b7200): recv r_subscribe
00:41.600p SOFI nua(0x7b7200): signal r_subscribe
00:41.601p SOFI nua: nua_stack_set_params: entering
00:41.601p SOFI soa_clone(static::0x7b0e30, 0x798968, 0x7b7200) called
00:41.601p SOFI soa_set_params(static::0x7b7640, ...) called
00:41.603p SOFI nta_leg_tcreate(0x7b7da0)
00:41.603p SOFI nua(0x7b7200): adding subscribe usage with event
message-summary
00:41.605p SOFI nta: selecting scheme sip
00:41.605p SOFI tport(0x7b24e8): EXPENSIVE unresolved */192.168.72.130:5060
00:41.606p SOFI tport_tsend(0x7b24e8) tpn = */192.168.72.130:5060
00:41.606p SOFI tport_resolve addrinfo = 192.168.72.130:5060
00:41.606p SOFI tport_by_addrinfo(0x7b24e8): not found by name
*/192.168.72.130:5060
00:41.608p SOFI tport_vsend(0x7b24e8): 598 bytes of 598 to
*/192.168.72.130:5060
00:41.608p SOFI tport_vsend returned 598
00:41.608p SOFI nta: sent SUBSCRIBE (101441812) to */192.168.72.130:5060
00:41.609p SOFI tport_pend(0x7b24e8): pending 0x7b8118 for
udp/192.168.72.151:50001 (already 0)
00:41.609p SOFI tport_wakeup_pri(0x7b24e8): events IN
00:41.609p SOFI tport_recv_event(0x7b24e8)
00:41.621p SOFI tport_recv_iovec(0x7b24e8) msg 0x7b8ee0 from
(udp/192.168.72.151:50001) has 418 bytes, veclen = 1
00:41.622p SOFI tport_deliver(0x7b24e8): msg 0x7b8ee0 (418 bytes) from
udp/192.168.72.130:50001/sip next=(nil)
00:41.622p SOFI nta: received 200 OK for SUBSCRIBE (101441812)
00:41.623p SOFI nta: 200 OK is going to a transaction
00:41.623p SOFI nta_outgoing: RTT is 17.066 ms
00:41.623p SOFI tport_release(0x7b24e8): 0x7b8118 by 0x7b8928 with 0x7b8ee0
00:41.624p SOFI nua(): refresh subscribe after 32 seconds (in [32..32])
00:41.624p SOFI nua(): refresh subscribe after 32 seconds
00:41.624p SOFI nua(0x7b7200): event r_subscribe 200 OK
00:41.624p SOFI nua: nua_event: entering
00:41.625p CESC ce_ProcCallback: Rcvd event for nua=0x7b07b0,
pMkData=0x781158, nh=0x7b7200, hmagic=0x781158, sip=0x7b8f7c
00:41.625p CESC nua_r_subscribe event: 200 OK
(pMkData->mk=MK1=lineH=0x7b07b0)
00:41.625p CESC Discarding Event...
00:42.010p SOFI nta: timer set next to 4500 ms
00:46.510p SOFI nta: timer K fired, terminate REGISTER (101441812)
00:46.510p SOFI outgoing_reclaim_all((nil), (nil), 0x7e1ffc58)
00:46.511p SOFI nta_outgoing_timer: 0/0 resent, 0/0 tout, 1/2 term, 1/2
free
00:46.511p SOFI nta: timer set next to 110 ms
00:46.630p SOFI nta: timer K fired, terminate SUBSCRIBE (101441812)
00:46.630p SOFI outgoing_reclaim_all((nil), (nil), 0x7e1ffc58)
00:46.631p SOFI nta_outgoing_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/1
free
00:46.631p SOFI nta: timer not set
00:59.572p CE2S nua_unsubscribe(nh=0x7b7200,
00:59.572p CE2S SIPTAG_FROM(sip:[EMAIL PROTECTED]:5060),
00:59.572p CE2S SIPTAG_EVENT(message-summary),
00:59.572p CE2S SIPTAG_ACCEPT(application/simple-message-summary))
00:59.572p SOFI nua: nua_unsubscribe: entering
00:59.573p SOFI nua(0x7b7200): signal r_unsubscribe
00:59.573p SOFI nua(0x7b7200): recv r_unsubscribe
00:59.573p SOFI nua(0x7b7200): signal r_unsubscribe
00:59.573p SOFI nua: nua_stack_set_params: entering
00:59.574p SOFI soa_set_params(static::0x7b7640, ...) called
00:59.576p SOFI nta: selecting scheme sip
00:59.576p SOFI tport(0x7b24e8): EXPENSIVE unresolved */192.168.72.130:5060
00:59.577p SOFI tport_tsend(0x7b24e8) tpn = */192.168.72.130:5060
00:59.577p SOFI tport_resolve addrinfo = 192.168.72.130:5060
00:59.577p SOFI tport_by_addrinfo(0x7b24e8): not found by name
*/192.168.72.130:5060
00:59.579p SOFI tport_vsend(0x7b24e8): 610 bytes of 610 to
*/192.168.72.130:5060
00:59.579p SOFI tport_vsend returned 610
00:59.579p SOFI nta: sent SUBSCRIBE (101441813) to */192.168.72.130:5060
00:59.580p SOFI tport_pend(0x7b24e8): pending 0x7b8118 for
udp/192.168.72.151:50001 (already 0)
00:59.580p SOFI nta: timer set to 32000 ms
00:59.580p SOFI nta: timer shortened to 500 ms
00:59.581p SOFI tport_wakeup_pri(0x7b24e8): events IN
00:59.581p SOFI tport_recv_event(0x7b24e8)
00:59.581p SOFI tport_recv_iovec(0x7b24e8) msg 0x7b5888 from
(udp/192.168.72.151:50001) has 418 bytes, veclen = 1
00:59.583p SOFI tport_deliver(0x7b24e8): msg 0x7b5888 (418 bytes) from
udp/192.168.72.130:50001/sip next=(nil)
00:59.583p SOFI nta: received 200 OK for SUBSCRIBE (101441813)
00:59.583p SOFI nta: 200 OK is going to a transaction
00:59.584p SOFI nta_outgoing: RTT is 6.71 ms
00:59.584p SOFI tport_release(0x7b24e8): 0x7b8118 by 0x7b74e8 with 0x7b5888
00:59.584p SOFI nua(0x7b7200): event r_unsubscribe 200 OK
00:59.584p SOFI nua(0x7b7200): removing subscribe usage with event
message-summary
00:59.585p SOFI nta_leg_destroy(0x7b7da0)
00:59.585p SOFI nua: nua_event: entering
00:59.585p CESC ce_ProcCallback: Rcvd event for nua=0x7b07b0,
pMkData=0x781158, nh=0x7b7200, hmagic=0x781158, sip=0x7b5924
00:59.585p CESC nua_r_unsubscribe event: 200 OK
(pMkData->mk=MK1=lineH=0x7b07b0)
00:59.585p CESC Reporting Event S_UNSUBSCRIBED_2_MSG_EV...
00:59.620p CE2S nua_handle_destroy(nh=0x7b7200)
00:59.621p SOFI nua: nua_handle_destroy: entering
00:59.621p SOFI nua(0x7b7200): signal r_destroy
00:59.621p CE2S nua_unregister(nh=0x7b2f80)
00:59.621p SOFI nua: nua_unregister: entering
00:59.621p SOFI nua(0x7b2f80): signal r_unregister
00:59.622p SOFI nua(0x7b7200): recv r_destroy
00:59.622p SOFI nua(0x7b7200): signal r_destroy
00:59.622p SOFI nta_leg_destroy((nil))
00:59.622p SOFI soa_destroy(static::0x7b7640) called
00:59.623p SOFI nua(0x7b2f80): recv r_unregister
00:59.623p SOFI nua(0x7b2f80): signal r_unregister
00:59.623p SOFI nua: nua_stack_set_params: entering
00:59.623p SOFI soa_set_params(static::0x7b3360, ...) called
00:59.624p SOFI nua(0x7b2f80): adding already existing register usage
00:59.625p SOFI nta: selecting scheme sip
00:59.626p SOFI tport(0x7b24e8): EXPENSIVE unresolved */192.168.72.130:5060
00:59.626p SOFI tport_tsend(0x7b24e8) tpn = */192.168.72.130:5060
00:59.626p SOFI tport_resolve addrinfo = 192.168.72.130:5060
00:59.627p SOFI tport_by_addrinfo(0x7b24e8): not found by name
*/192.168.72.130:5060
00:59.628p SOFI tport_vsend(0x7b24e8): 500 bytes of 500 to
*/192.168.72.130:5060
00:59.629p SOFI tport_vsend returned 500
00:59.629p SOFI nta: sent REGISTER (101441813) to */192.168.72.130:5060
00:59.629p SOFI tport_pend(0x7b24e8): pending 0x7b5dc0 for
udp/192.168.72.151:50001 (already 0)
00:59.630p SOFI tport_wakeup_pri(0x7b24e8): events IN
00:59.631p SOFI tport_recv_event(0x7b24e8)
00:59.631p SOFI tport_recv_iovec(0x7b24e8) msg 0x7c9410 from
(udp/192.168.72.151:50001) has 431 bytes, veclen = 1
00:59.633p SOFI tport_deliver(0x7b24e8): msg 0x7c9410 (431 bytes) from
udp/192.168.72.130:50001/sip next=(nil)
00:59.633p SOFI nta: received 100 Trying for REGISTER (101441813)
00:59.633p SOFI nta: 100 Trying is going to a transaction
00:59.633p SOFI nta_outgoing: RTT is 7.299 ms
00:59.634p SOFI tport_release(0x7b24e8): 0x7b5dc0 by 0x7b9670 with 0x7c9410
(preliminary)
00:59.634p SOFI nua(0x7b2f80): event r_unregister 100 Trying
00:59.634p SOFI nua: nua_event: entering
00:59.634p CESC ce_ProcCallback: Rcvd event for nua=0x7b07b0,
pMkData=0x781158, nh=0x7b2f80, hmagic=0x781158, sip=0x7c94ac
00:59.634p CESC nua_r_unregister event: 100 Trying
(pMkData->mk=MK1=lineH=0x7b07b0)
00:59.635p CESC Discarding Event...
00:59.635p SOFI tport_wakeup_pri(0x7b24e8): events IN
00:59.635p SOFI tport_recv_event(0x7b24e8)
00:59.635p SOFI tport_recv_iovec(0x7b24e8) msg 0x7c99e0 from
(udp/192.168.72.151:50001) has 454 bytes, veclen = 1
00:59.637p SOFI tport_deliver(0x7b24e8): msg 0x7c99e0 (454 bytes) from
udp/192.168.72.130:50001/sip next=(nil)
00:59.637p SOFI nta: received 200 OK for REGISTER (101441813)
00:59.638p SOFI nta: 200 OK is going to a transaction
00:59.638p SOFI tport_release(0x7b24e8): 0x7b5dc0 by 0x7b9670 with 0x7c99e0
00:59.638p SOFI nua(0x7b2f80): event r_unregister 200 OK
00:59.638p SOFI nua(0x7b2f80): removing register usage
00:59.639p SOFI nta_leg_destroy(0x7b3b70)
00:59.639p SOFI nua: nua_event: entering
00:59.639p CESC ce_ProcCallback: Rcvd event for nua=0x7b07b0,
pMkData=0x781158, nh=0x7b2f80, hmagic=0x781158, sip=0x7c9a7c
00:59.639p CESC nua_r_unregister event: 200 OK
(pMkData->mk=MK1=lineH=0x7b07b0)
00:59.639p CESC Reporting Event S_UNREGISTERED_EV...
00:59.707p CE2S nua_handle_destroy(nh=0x7b2f80)
00:59.708p SOFI nua: nua_handle_destroy: entering
00:59.708p SOFI nua(0x7b2f80): signal r_destroy
00:59.708p CE2S nua_shutdown(nua=0x7b07b0)
00:59.708p SOFI nua: nua_shutdown: entering
00:59.708p SOFI nua((nil)): signal r_shutdown
00:59.709p SOFI nua(0x7b2f80): recv r_destroy
00:59.709p SOFI nua(0x7b2f80): signal r_destroy
00:59.709p SOFI nta_leg_destroy((nil))
00:59.709p SOFI soa_destroy(static::0x7b3360) called
00:59.709p SOFI nua((nil)): recv r_shutdown
00:59.709p SOFI nua((nil)): signal r_shutdown
00:59.710p SOFI nua: nua_stack_shutdown: entering
00:59.710p SOFI soa_destroy(static::0x7b0e30) called
00:59.710p SOFI nta: outgoing_free(0x7b9670)
00:59.711p SOFI nta: outgoing_free(0x7b74e8)
00:59.711p SOFI sres_sofia_update(0x7b1ec0, -1, -1)
00:59.712p SOFI sres_sofia_update((nil), -1, -1)
00:59.712p SOFI tport_destroy(0x7b2110)
00:59.712p SOFI nua((nil)): event r_shutdown 200 Shutdown successful
00:59.713p SOFI nua: nua_event: entering
00:59.713p CESC ce_ProcCallback: Rcvd event for nua=0x7b07b0,
pMkData=0x781158, nh=0x0, hmagic=0x0, sip=0x0
00:59.713p CESC nua_r_shutdown event: 200 Shutdown successful
(pMkData->mk=MK1=lineH=0x7b07b0)
00:59.713p CESC Reporting Event S_SHUTDOWN_COMPLETE_EV...
00:59.730p CE2S nua_destroy(nua=0x7b07b0)
00:59.730p SOFI nua: nua_destroy: entering
00:59.731p SOFI nua: nua_stack_deinit: entering
01:00.242p CE2S su_root_threading(self=0x7988e0, enable=0)
01:00.242p CE2S ...su_root_threading() returned 0x0
01:00.242p CE2S nua_create(root=0x7988e0, callback=0x550d9c,
magic=0x781158, url=sip:192.168.72.151:50001)
01:00.242p SOFI nua: nua_create: entering
01:00.243p SOFI nua: nua_stack_init: entering
01:00.243p SOFI nua: nua_stack_set_params: entering
01:00.243p SOFI soa_create("default", 0x798950, 0x7b70a0) called
01:00.244p SOFI soa_set_params(static::0x7b4ed8, ...) called
01:00.244p SOFI nta_agent_create: initialized hash tables
01:00.244p SOFI nta_agent_create: initialized transports
01:00.245p SOFI nta_agent_create: initialized random identifiers
01:00.245p SOFI nta_agent_create: initialized timer
01:00.246p SOFI nta_agent_create: initialized resolver
01:00.247p SOFI tport_create(): 0x7b7ad0
01:00.247p SOFI nta: master transport created
01:00.248p SOFI tport_bind_server(0x7b7ad0) to */192.168.72.151:50001/sip
01:00.248p SOFI tport_bind_server(0x7b7ad0): calling tport_listen for udp
01:00.248p SOFI tport_alloc_primary(0x7b7ad0): new primary tport 0x7b51b8
01:00.249p SOFI tport_listen(0x7b51b8): listening at
udp/192.168.72.151:50001/sip
01:00.260p SOFI tport_bind_server(0x7b7ad0): calling tport_listen for tcp
01:00.261p SOFI tport_alloc_primary(0x7b7ad0): new primary tport 0x7b5458
01:00.262p SOFI tport_listen(0x7b5458): listening at
tcp/192.168.72.151:50001/sip
01:00.262p SOFI nta: bound to (192.168.72.151:50001;transport=*)
01:00.262p SOFI nta: agent_init_via: SIP/2.0/udp 192.168.72.151:50001 (sip)
01:00.263p SOFI nta: agent_init_via: SIP/2.0/tcp 192.168.72.151:50001 (sip)
01:00.263p SOFI nta: Via fields initialized
01:00.264p SOFI nta: Contact header created
01:00.264p SOFI nua_register: Adding contact URL '192.168.72.151' to list.
01:00.265p CE2S ...nua_create() returned
mkData[la].pLine->lineH=0x7b8420
01:00.265p CE2S nua_set_params(nua=0x7b8420, NUTAG_ALLOW_EVENTS(dialog))
01:00.266p SOFI nua: nua_set_params: entering
01:00.266p SOFI nua((nil)): signal r_set_params
01:00.266p CE2S nua_set_params(nua=0x7b8420, NUTAG_ALLOW_EVENTS(sla))
01:00.266p SOFI nua: nua_set_params: entering
01:00.266p SOFI nua((nil)): signal r_set_params
01:00.267p CE2S nua_set_params(nua=0x7b8420,
NUTAG_ALLOW_EVENTS(include-session-description))
01:00.267p SOFI nua: nua_set_params: entering
01:00.267p SOFI nua((nil)): signal r_set_params
01:00.267p CE2S [2]nua_handle(nua=0x7b8420, hmagic=0x781158,
url=sip:[EMAIL PROTECTED]:5060)
01:00.267p SOFI nua: nh_create_handle: entering
01:00.268p CE2S ...[2]nua_handle() returned nh=0x7b88b0
01:00.268p CE2S nua_register(nh=0x7b88b0,
SIPTAG_FROM(sip:[EMAIL PROTECTED]:5060),
01:00.268p CE2S NUTAG_M_DISPLAY(), NUTAG_M_USERNAME(10282),
01:00.268p CE2S
NUTAG_M_FEATURES(reg-id=1804289383;+sip.instance="<urn:uuid:c39b0000-4f96-1a
00-1000-00048d0000b8>")
01:00.268p CE2S NUTAG_OUTBOUND(no-validate no-natify
no-options-keepalive))
01:00.269p SOFI nua: nua_register: entering
01:00.269p SOFI nua(0x7b88b0): signal r_register
01:00.280p SOFI nua((nil)): recv r_set_params
01:00.281p SOFI nua((nil)): signal r_set_params
01:00.281p SOFI nua: nua_stack_set_params: entering
01:00.281p SOFI soa_set_params(static::0x7b4ed8, ...) called
01:00.282p SOFI nua((nil)): event r_set_params 200 OK
01:00.282p SOFI nua((nil)): recv r_set_params
01:00.282p SOFI nua((nil)): signal r_set_params
01:00.282p SOFI nua: nua_stack_set_params: entering
01:00.283p SOFI soa_set_params(static::0x7b4ed8, ...) called
01:00.283p SOFI nua((nil)): event r_set_params 200 OK
01:00.284p SOFI nua((nil)): recv r_set_params
01:00.284p SOFI nua((nil)): signal r_set_params
01:00.284p SOFI nua: nua_stack_set_params: entering
01:00.284p SOFI soa_set_params(static::0x7b4ed8, ...) called
01:00.285p SOFI nua((nil)): event r_set_params 200 OK
01:00.285p SOFI nua(0x7b88b0): recv r_register
01:00.285p SOFI nua(0x7b88b0): signal r_register
01:00.285p SOFI nua: nua_stack_set_params: entering
01:00.286p SOFI soa_clone(static::0x7b4ed8, 0x798950, 0x7b88b0) called
01:00.286p SOFI soa_set_params(static::0x7b8cb8, ...) called
01:00.287p SOFI nta_leg_tcreate(0x7b8868)
01:00.288p SOFI nua(0x7b88b0): adding register usage
01:00.310p SOFI nta: selecting scheme sip
01:00.311p SOFI tport(0x7b51b8): EXPENSIVE unresolved */192.168.72.130:5060
01:00.311p SOFI tport_tsend(0x7b51b8) tpn = */192.168.72.130:5060
01:00.312p SOFI tport_resolve addrinfo = 192.168.72.130:5060
01:00.312p SOFI tport_by_addrinfo(0x7b51b8): not found by name
*/192.168.72.130:5060
01:00.313p SOFI tport_vsend(0x7b51b8): 601 bytes of 601 to
*/192.168.72.130:5060
01:00.313p SOFI tport_vsend returned 601
01:00.314p SOFI nta: sent REGISTER (101441822) to */192.168.72.130:5060
01:00.314p SOFI tport_pend(0x7b51b8): pending 0x7b0808 for
udp/192.168.72.151:50001 (already 0)
01:00.314p SOFI nta: timer set to 32000 ms
01:00.315p SOFI nta: timer shortened to 500 ms
01:00.315p SOFI tport_wakeup_pri(0x7b51b8): events IN
01:00.315p SOFI tport_recv_event(0x7b51b8)
01:00.316p SOFI tport_recv_iovec(0x7b51b8) msg 0x7b15e8 from
(udp/192.168.72.151:50001) has 431 bytes, veclen = 1
01:00.317p SOFI tport_deliver(0x7b51b8): msg 0x7b15e8 (431 bytes) from
udp/192.168.72.130:50001/sip next=(nil)
01:00.317p SOFI nta: received 100 Trying for REGISTER (101441822)
01:00.318p SOFI nta: 100 Trying is going to a transaction
01:00.318p SOFI nta_outgoing: RTT is 6.659 ms
01:00.318p SOFI tport_release(0x7b51b8): 0x7b0808 by 0x7b0fa8 with 0x7b15e8
(preliminary)
01:00.318p SOFI nua(0x7b88b0): event r_register 100 Trying
01:00.319p SOFI nua: nua_event: entering
01:00.319p CESC ce_ProcCallback: Rcvd event for nua=0x7b8420,
pMkData=0x781158, nh=0x0, hmagic=0x0, sip=0x0
01:00.319p CESC nua_r_set_params event: 200 OK
(pMkData->mk=MK1=lineH=0x7b8420)
01:00.319p CESC Discarding Event...
01:00.319p SOFI nua: nua_event: entering
01:00.319p CESC ce_ProcCallback: Rcvd event for nua=0x7b8420,
pMkData=0x781158, nh=0x0, hmagic=0x0, sip=0x0
01:00.319p CESC nua_r_set_params event: 200 OK
(pMkData->mk=MK1=lineH=0x7b8420)
01:00.319p CESC Discarding Event...
01:00.340p SOFI nua: nua_event: entering
01:00.340p CESC ce_ProcCallback: Rcvd event for nua=0x7b8420,
pMkData=0x781158, nh=0x0, hmagic=0x0, sip=0x0
01:00.340p CESC nua_r_set_params event: 200 OK
(pMkData->mk=MK1=lineH=0x7b8420)
01:00.340p CESC Discarding Event...
01:00.341p SOFI nua: nua_event: entering
01:00.341p CESC ce_ProcCallback: Rcvd event for nua=0x7b8420,
pMkData=0x781158, nh=0x7b88b0, hmagic=0x781158, sip=0x7b1684
01:00.341p CESC nua_r_register event: 100 Trying
(pMkData->mk=MK1=lineH=0x7b8420)
01:00.341p CESC Handled Event Locally...
01:00.341p SOFI tport_wakeup_pri(0x7b51b8): events IN
01:00.341p SOFI tport_recv_event(0x7b51b8)
01:00.342p SOFI tport_recv_iovec(0x7b51b8) msg 0x7b1df0 from
(udp/192.168.72.151:50001) has 511 bytes, veclen = 1
01:00.344p SOFI tport_deliver(0x7b51b8): msg 0x7b1df0 (511 bytes) from
udp/192.168.72.130:50001/sip next=(nil)
01:00.344p SOFI nta: received 200 OK for REGISTER (101441822)
01:00.344p SOFI nta: 200 OK is going to a transaction
01:00.344p SOFI tport_release(0x7b51b8): 0x7b0808 by 0x7b0fa8 with 0x7b1df0
01:00.345p SOFI nua(): refresh register after 61 seconds (in [60..90])
01:00.345p SOFI nua(): refresh register after 61 seconds
01:00.345p SOFI nua(0x7b88b0): event r_register 200 OK
01:00.346p SOFI nua: nua_event: entering
01:00.346p CESC ce_ProcCallback: Rcvd event for nua=0x7b8420,
pMkData=0x781158, nh=0x7b88b0, hmagic=0x781158, sip=0x7b1e8c
01:00.346p CESC nua_r_register event: 200 OK
(pMkData->mk=MK1=lineH=0x7b8420)
01:00.346p CESC Reporting Event S_REGISTERED_EV...
01:00.364p CE2S [2]nua_handle(nua=0x7b8420, hmagic=0x781158,
url=sip:[EMAIL PROTECTED]:5060)
01:00.364p SOFI nua: nh_create_handle: entering
01:00.365p CE2S ...[2]nua_handle() returned nh=0x7b26f8
01:00.365p CE2S nua_subscribe(nh=0x7b26f8, NUTAG_M_DISPLAY()
01:00.365p CE2S SIPTAG_FROM(sip:[EMAIL PROTECTED]:5060),
NUTAG_M_USERNAME(10282),
01:00.365p CE2S SIPTAG_EVENT(message-summary),
SIPTAG_ACCEPT(application/simple-message-summary),
01:00.366p CE2S SIPTAG_EXPIRES(3600), NUTAG_OUTBOUND(no-validate
no-natify no-options-keepalive))
01:00.366p SOFI nua: nua_subscribe: entering
01:00.366p SOFI nua(0x7b26f8): signal r_subscribe
01:00.369p SOFI nua(0x7b26f8): recv r_subscribe
01:00.369p SOFI nua(0x7b26f8): signal r_subscribe
01:00.369p SOFI nua: nua_stack_set_params: entering
01:00.370p SOFI soa_clone(static::0x7b4ed8, 0x798950, 0x7b26f8) called
01:00.371p SOFI soa_set_params(static::0x7b2ae0, ...) called
01:00.372p SOFI nta_leg_tcreate(0x7ca5e0)
01:00.372p SOFI nua(0x7b26f8): adding subscribe usage with event
message-summary
01:00.374p SOFI nta: selecting scheme sip
01:00.375p SOFI tport(0x7b51b8): EXPENSIVE unresolved */192.168.72.130:5060
01:00.375p SOFI tport_tsend(0x7b51b8) tpn = */192.168.72.130:5060
01:00.375p SOFI tport_resolve addrinfo = 192.168.72.130:5060
01:00.376p SOFI tport_by_addrinfo(0x7b51b8): not found by name
*/192.168.72.130:5060
01:00.377p SOFI tport_vsend(0x7b51b8): 598 bytes of 598 to
*/192.168.72.130:5060
01:00.377p SOFI tport_vsend returned 598
01:00.378p SOFI nta: sent SUBSCRIBE (101441822) to */192.168.72.130:5060
01:00.378p SOFI tport_pend(0x7b51b8): pending 0x7ca958 for
udp/192.168.72.151:50001 (already 0)
01:00.378p SOFI tport_wakeup_pri(0x7b51b8): events IN
01:00.379p SOFI tport_recv_event(0x7b51b8)
01:00.379p SOFI tport_recv_iovec(0x7b51b8) msg 0x7cb700 from
(udp/192.168.72.151:50001) has 418 bytes, veclen = 1
01:00.391p SOFI tport_deliver(0x7b51b8): msg 0x7cb700 (418 bytes) from
udp/192.168.72.130:50001/sip next=(nil)
01:00.391p SOFI nta: received 200 OK for SUBSCRIBE (101441822)
01:00.392p SOFI nta: 200 OK is going to a transaction
01:00.392p SOFI nta_outgoing: RTT is 16.647 ms
01:00.392p SOFI tport_release(0x7b51b8): 0x7ca958 by 0x7cb148 with 0x7cb700
01:00.393p SOFI nua(): refresh subscribe after 32 seconds (in [32..32])
01:00.393p SOFI nua(): refresh subscribe after 32 seconds
01:00.393p SOFI nua(0x7b26f8): event r_subscribe 200 OK
01:00.394p SOFI nua: nua_event: entering
01:00.394p CESC ce_ProcCallback: Rcvd event for nua=0x7b8420,
pMkData=0x781158, nh=0x7b26f8, hmagic=0x781158, sip=0x7cb79c
01:00.394p CESC nua_r_subscribe event: 200 OK
(pMkData->mk=MK1=lineH=0x7b8420)
01:00.394p CESC Discarding Event...
01:00.830p SOFI nta: timer set next to 4513 ms
01:05.360p SOFI nta: timer K fired, terminate REGISTER (101441822)
01:05.360p SOFI outgoing_reclaim_all((nil), (nil), 0x7e1ffc58)
01:05.361p SOFI nta_outgoing_timer: 0/0 resent, 0/0 tout, 1/2 term, 1/2
free
01:05.361p SOFI nta: timer set next to 20 ms
01:05.380p SOFI nta: timer K fired, terminate SUBSCRIBE (101441822)
01:05.380p SOFI outgoing_reclaim_all((nil), (nil), 0x7e1ffc58)
01:05.381p SOFI nta_outgoing_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/1
free
01:05.381p SOFI nta: timer not set
01:14.982p CE2S nua_unsubscribe(nh=0x7b26f8,
01:14.982p CE2S SIPTAG_FROM(sip:[EMAIL PROTECTED]:5060),
01:14.982p CE2S SIPTAG_EVENT(message-summary),
01:14.982p CE2S SIPTAG_ACCEPT(application/simple-message-summary))
01:14.983p SOFI nua: nua_unsubscribe: entering
01:14.983p SOFI nua(0x7b26f8): signal r_unsubscribe
01:14.983p SOFI nua(0x7b26f8): recv r_unsubscribe
01:14.984p SOFI nua(0x7b26f8): signal r_unsubscribe
01:14.984p SOFI nua: nua_stack_set_params: entering
01:14.984p SOFI soa_set_params(static::0x7b2ae0, ...) called
01:14.986p SOFI nta: selecting scheme sip
01:14.987p SOFI tport(0x7b51b8): EXPENSIVE unresolved */192.168.72.130:5060
01:14.987p SOFI tport_tsend(0x7b51b8) tpn = */192.168.72.130:5060
01:14.987p SOFI tport_resolve addrinfo = 192.168.72.130:5060
01:14.988p SOFI tport_by_addrinfo(0x7b51b8): not found by name
*/192.168.72.130:5060
01:14.989p SOFI tport_vsend(0x7b51b8): 610 bytes of 610 to
*/192.168.72.130:5060
01:14.989p SOFI tport_vsend returned 610
01:14.990p SOFI nta: sent SUBSCRIBE (101441823) to */192.168.72.130:5060
01:14.990p SOFI tport_pend(0x7b51b8): pending 0x7ca9f8 for
udp/192.168.72.151:50001 (already 0)
01:14.991p SOFI nta: timer set to 32000 ms
01:14.991p SOFI nta: timer shortened to 500 ms
01:14.991p SOFI tport_wakeup_pri(0x7b51b8): events IN
01:14.991p SOFI tport_recv_event(0x7b51b8)
01:14.992p SOFI tport_recv_iovec(0x7b51b8) msg 0x7ca1e8 from
(udp/192.168.72.151:50001) has 418 bytes, veclen = 1
01:14.993p SOFI tport_deliver(0x7b51b8): msg 0x7ca1e8 (418 bytes) from
udp/192.168.72.130:50001/sip next=(nil)
01:14.993p SOFI nta: received 200 OK for SUBSCRIBE (101441823)
01:14.994p SOFI nta: 200 OK is going to a transaction
01:14.994p SOFI nta_outgoing: RTT is 6.677 ms
01:14.994p SOFI tport_release(0x7b51b8): 0x7ca9f8 by 0x7b29d8 with 0x7ca1e8
01:14.994p SOFI nua(0x7b26f8): event r_unsubscribe 200 OK
01:14.995p SOFI nua(0x7b26f8): removing subscribe usage with event
message-summary
01:14.995p SOFI nta_leg_destroy(0x7ca5e0)
01:14.995p SOFI nua: nua_event: entering
01:14.995p CESC ce_ProcCallback: Rcvd event for nua=0x7b8420,
pMkData=0x781158, nh=0x7b26f8, hmagic=0x781158, sip=0x7ca284
01:14.996p CESC nua_r_unsubscribe event: 200 OK
(pMkData->mk=MK1=lineH=0x7b8420)
01:14.996p CESC Reporting Event S_UNSUBSCRIBED_2_MSG_EV...
01:15.030p CE2S nua_handle_destroy(nh=0x7b26f8)
01:15.030p SOFI nua: nua_handle_destroy: entering
01:15.031p SOFI nua(0x7b26f8): signal r_destroy
01:15.031p CE2S nua_unregister(nh=0x7b88b0)
01:15.031p SOFI nua: nua_unregister: entering
01:15.031p SOFI nua(0x7b88b0): signal r_unregister
01:15.032p SOFI nua(0x7b26f8): recv r_destroy
01:15.032p SOFI nua(0x7b26f8): signal r_destroy
01:15.032p SOFI nta_leg_destroy((nil))
01:15.032p SOFI soa_destroy(static::0x7b2ae0) called
01:15.032p SOFI nua(0x7b88b0): recv r_unregister
01:15.033p SOFI nua(0x7b88b0): signal r_unregister
01:15.033p SOFI nua: nua_stack_set_params: entering
01:15.033p SOFI soa_set_params(static::0x7b8cb8, ...) called
01:15.034p SOFI nua(0x7b88b0): adding already existing register usage
01:15.035p SOFI nta: selecting scheme sip
01:15.036p SOFI tport(0x7b51b8): EXPENSIVE unresolved */192.168.72.130:5060
01:15.036p SOFI tport_tsend(0x7b51b8) tpn = */192.168.72.130:5060
01:15.036p SOFI tport_resolve addrinfo = 192.168.72.130:5060
01:15.037p SOFI tport_by_addrinfo(0x7b51b8): not found by name
*/192.168.72.130:5060
01:15.038p SOFI tport_vsend(0x7b51b8): 500 bytes of 500 to
*/192.168.72.130:5060
01:15.038p SOFI tport_vsend returned 500
01:15.038p SOFI nta: sent REGISTER (101441823) to */192.168.72.130:5060
01:15.039p SOFI tport_pend(0x7b51b8): pending 0x7b12f0 for
udp/192.168.72.151:50001 (already 0)
01:15.039p SOFI tport_wakeup_pri(0x7b51b8): events IN
01:15.039p SOFI tport_recv_event(0x7b51b8)
01:15.041p SOFI tport_recv_iovec(0x7b51b8) msg 0x7dbad8 from
(udp/192.168.72.151:50001) has 431 bytes, veclen = 1
01:15.061p FLSH @CE_UTIL #327:UNEXPECTED SIP MONITOR SIGNAL RAISED
(11:SIGSEGV:Segmentation violation)
----------------------------END OF TRACE--------------------------------
-------------------------------------------------------------------------
This SF.net email is sponsored by: Splunk Inc.
Still grepping through log files to find problems? Stop.
Now Search log events and configuration files using AJAX and a browser.
Download your FREE copy of Splunk now >> http://get.splunk.com/
_______________________________________________
Sofia-sip-devel mailing list
Sofia-sip-devel@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/sofia-sip-devel
