17 Sep
2014
17 Sep
'14
1:52 a.m.
THIS IS AN AUTOMATED MESSAGE, DO NOT REPLY.
The following task has a new comment added:
FS#424 - zombie dialogs in state 5
User who did this - Ovidiu Sas (osas)
----------
You got all the logs before (tm and dialog in debug mode). Here are all the logs in full
debug.
The dialog is still there:
Sep 16 18:49:50 centos k[28620]: DEBUG: <core> [parser/msg_parser.c:623]:
parse_msg(): SIP Request:
Sep 16 18:49:50 centos k[28620]: DEBUG: <core> [parser/msg_parser.c:625]:
parse_msg(): method: <BYE>
Sep 16 18:49:50 centos k[28620]: DEBUG: <core> [parser/msg_parser.c:627]:
parse_msg(): uri: <sip:4165552222@192.168.2.97:5064>
Sep 16 18:49:50 centos k[28620]: DEBUG: <core> [parser/msg_parser.c:629]:
parse_msg(): version: <SIP/2.0>
Sep 16 18:49:50 centos k[28620]: DEBUG: <core> [parser/parse_via.c:1284]:
parse_via_param(): Found param type 232, <branch> = <z9hG4bK72762b8e>;
state=6
Sep 16 18:49:50 centos k[28620]: DEBUG: <core> [parser/parse_via.c:1284]:
parse_via_param(): Found param type 235, <rport> = <n/a>; state=17
Sep 16 18:49:50 centos k[28620]: DEBUG: <core> [parser/parse_via.c:2672]:
parse_via(): end of header reached, state=5
Sep 16 18:49:50 centos k[28620]: DEBUG: <core> [parser/msg_parser.c:513]:
parse_headers(): parse_headers: Via found, flags=2
Sep 16 18:49:50 centos k[28620]: DEBUG: <core> [parser/msg_parser.c:515]:
parse_headers(): parse_headers: this is the first via
Sep 16 18:49:50 centos k[28620]: DEBUG: <core> [receive.c:154]: receive_msg(): After
parse_msg...
Sep 16 18:49:50 centos k[28620]: DEBUG: <core> [receive.c:197]: receive_msg():
preparing to run routing scripts...
Sep 16 18:49:50 centos k[28620]: DEBUG: <core> [parser/parse_addr_spec.c:176]:
parse_to_param(): DEBUG: add_param: tag=as0f39dff6
Sep 16 18:49:50 centos k[28620]: DEBUG: <core> [parser/parse_addr_spec.c:898]:
parse_addr_spec(): end of header reached, state=29
Sep 16 18:49:50 centos k[28620]: DEBUG: <core> [parser/parse_addr_spec.c:176]:
parse_to_param(): DEBUG: add_param: tag=d0da9d2543fc82fco4
Sep 16 18:49:50 centos k[28620]: DEBUG: <core> [parser/parse_addr_spec.c:898]:
parse_addr_spec(): end of header reached, state=29
Sep 16 18:49:50 centos k[28620]: DEBUG: <core> [parser/msg_parser.c:190]:
get_hdr_field(): DEBUG: get_hdr_field: <To> [54]; uri=[sip:4165552222@192.168.2.62]
Sep 16 18:49:50 centos k[28620]: DEBUG: <core> [parser/msg_parser.c:192]:
get_hdr_field(): DEBUG: to body [<sip:4165552222@192.168.2.62>]
Sep 16 18:49:50 centos k[28620]: DEBUG: <core> [parser/msg_parser.c:170]:
get_hdr_field(): get_hdr_field: cseq <CSeq>: <102> <BYE>
Sep 16 18:49:50 centos k[28620]: DEBUG: <core> [parser/msg_parser.c:204]:
get_hdr_field(): DEBUG: get_hdr_body : content_length=0
Sep 16 18:49:50 centos k[28620]: DEBUG: <core> [parser/msg_parser.c:106]:
get_hdr_field(): found end of header
Sep 16 18:49:50 centos k[28620]: DEBUG: pv [pv_core.c:385]: pv_get_contact(): no contact
header!
Sep 16 18:49:50 centos k[28620]: INFO: <script>: [2] BYE
sip:4165552222@192.168.2.97:5064 From:sip:1234@192.168.2.62,tag=as0f39dff6
To:sip:4165552222@192.168.2.62,tag=d0da9d2543fc82fco4
Call-ID:d0d61319-383c6598@192.168.2.97 Contact:<null>
<192.168.2.2:5060->udp:192.168.2.62:5060>
Sep 16 18:49:50 centos k[28620]: DEBUG: maxfwd [mf_funcs.c:85]: is_maxfwd_present(): value
= 70
Sep 16 18:49:50 centos k[28620]: DEBUG: siputils [checks.c:106]: has_totag(): totag found
Sep 16 18:49:50 centos k[28620]: DEBUG: rr [loose.c:90]: is_preloaded(): is_preloaded: No
Sep 16 18:49:50 centos k[28620]: DEBUG: <core> [socket_info.c:583]:
grep_sock_info(): grep_sock_info - checking if host==us: 12==12 && [192.168.2.97]
== [192.168.2.62]
Sep 16 18:49:50 centos k[28620]: DEBUG: <core> [socket_info.c:587]:
grep_sock_info(): grep_sock_info - checking if port 5060 (advertise 0) matches port 5064
Sep 16 18:49:50 centos k[28620]: DEBUG: <core> [socket_info.c:583]:
grep_sock_info(): grep_sock_info - checking if host==us: 12==12 && [192.168.2.97]
== [192.168.2.62]
Sep 16 18:49:50 centos k[28620]: DEBUG: <core> [socket_info.c:587]:
grep_sock_info(): grep_sock_info - checking if port 8080 (advertise 0) matches port 5064
Sep 16 18:49:50 centos k[28620]: DEBUG: <core> [forward.c:454]: check_self():
check_self: host != me
Sep 16 18:49:50 centos k[28620]: DEBUG: <core> [socket_info.c:583]:
grep_sock_info(): grep_sock_info - checking if host==us: 12==12 && [192.168.2.62]
== [192.168.2.62]
Sep 16 18:49:50 centos k[28620]: DEBUG: <core> [socket_info.c:587]:
grep_sock_info(): grep_sock_info - checking if port 5060 (advertise 0) matches port 5060
Sep 16 18:49:50 centos k[28620]: DEBUG: rr [loose.c:785]: after_loose(): Topmost route
URI: 'sip:192.168.2.62;lr;ftag=d0da9d2543fc82fco4;did=10c.b9a' is me
Sep 16 18:49:50 centos k[28620]: DEBUG: <core> [parser/msg_parser.c:106]:
get_hdr_field(): found end of header
Sep 16 18:49:50 centos k[28620]: DEBUG: rr [loose.c:181]: find_next_route(): No next Route
HF found
Sep 16 18:49:50 centos k[28620]: DEBUG: rr [loose.c:809]: after_loose(): No next URI
found
Sep 16 18:49:50 centos k[28620]: DEBUG: rr [rr_cb.c:97]: run_rr_callbacks(): callback id 0
entered with <lr;ftag=d0da9d2543fc82fco4;did=10c.b9a>
Sep 16 18:49:50 centos k[28620]: DEBUG: dialog [dlg_handlers.c:1163]: dlg_onroute(): route
param is '10c.b9a' (len=7)
Sep 16 18:49:50 centos k[28620]: DEBUG: dialog [dlg_hash.c:654]: dlg_lookup(): ref dlg
0x7ffd35cf9070 with 1 -> 3
Sep 16 18:49:50 centos k[28620]: DEBUG: dialog [dlg_hash.c:656]: dlg_lookup(): dialog
id=2715 found on entry 3073
Sep 16 18:49:50 centos k[28620]: DEBUG: dialog [dlg_profile.c:511]: set_current_dialog():
setting current dialog [3073:2715]
Sep 16 18:49:50 centos k[28620]: DEBUG: dialog [dlg_hash.c:1066]: next_state_dlg(): dialog
0x7ffd35cf9070 changed from state 4 to state 5, due event 7 (ref 3)
Sep 16 18:49:50 centos k[28620]: DEBUG: dialog [dlg_hash.c:854]: dlg_ref(): ref dlg
0x7ffd35cf9070 with 1 -> 4
Sep 16 18:49:50 centos k[28620]: DEBUG: dialog [dlg_handlers.c:1552]:
dlg_run_event_route(): executing event_route 1 on state 5
Sep 16 18:49:50 centos k[28620]: INFO: <script>: [2] entering
event_route[dialog:end]
Sep 16 18:49:50 centos k[28620]: DEBUG: cfgutils [cfgutils.c:675]: m_usleep(): sleep
1300000 microseconds
Sep 16 18:49:50 centos k[28617]: DEBUG: <core> [parser/msg_parser.c:623]:
parse_msg(): SIP Request:
Sep 16 18:49:50 centos k[28617]: DEBUG: <core> [parser/msg_parser.c:625]:
parse_msg(): method: <BYE>
Sep 16 18:49:50 centos k[28617]: DEBUG: <core> [parser/msg_parser.c:627]:
parse_msg(): uri: <sip:4165552222@192.168.2.97:5064>
Sep 16 18:49:50 centos k[28617]: DEBUG: <core> [parser/msg_parser.c:629]:
parse_msg(): version: <SIP/2.0>
Sep 16 18:49:50 centos k[28617]: DEBUG: <core> [parser/parse_via.c:1284]:
parse_via_param(): Found param type 232, <branch> = <z9hG4bK72762b8e>;
state=6
Sep 16 18:49:50 centos k[28617]: DEBUG: <core> [parser/parse_via.c:1284]:
parse_via_param(): Found param type 235, <rport> = <n/a>; state=17
Sep 16 18:49:50 centos k[28617]: DEBUG: <core> [parser/parse_via.c:2672]:
parse_via(): end of header reached, state=5
Sep 16 18:49:50 centos k[28617]: DEBUG: <core> [parser/msg_parser.c:513]:
parse_headers(): parse_headers: Via found, flags=2
Sep 16 18:49:50 centos k[28617]: DEBUG: <core> [parser/msg_parser.c:515]:
parse_headers(): parse_headers: this is the first via
Sep 16 18:49:50 centos k[28617]: DEBUG: <core> [receive.c:154]: receive_msg(): After
parse_msg...
Sep 16 18:49:50 centos k[28617]: DEBUG: <core> [receive.c:197]: receive_msg():
preparing to run routing scripts...
Sep 16 18:49:50 centos k[28617]: DEBUG: <core> [parser/parse_addr_spec.c:176]:
parse_to_param(): DEBUG: add_param: tag=as0f39dff6
Sep 16 18:49:50 centos k[28617]: DEBUG: <core> [parser/parse_addr_spec.c:898]:
parse_addr_spec(): end of header reached, state=29
Sep 16 18:49:50 centos k[28617]: DEBUG: <core> [parser/parse_addr_spec.c:176]:
parse_to_param(): DEBUG: add_param: tag=d0da9d2543fc82fco4
Sep 16 18:49:50 centos k[28617]: DEBUG: <core> [parser/parse_addr_spec.c:898]:
parse_addr_spec(): end of header reached, state=29
Sep 16 18:49:50 centos k[28617]: DEBUG: <core> [parser/msg_parser.c:190]:
get_hdr_field(): DEBUG: get_hdr_field: <To> [54]; uri=[sip:4165552222@192.168.2.62]
Sep 16 18:49:50 centos k[28617]: DEBUG: <core> [parser/msg_parser.c:192]:
get_hdr_field(): DEBUG: to body [<sip:4165552222@192.168.2.62>]
Sep 16 18:49:50 centos k[28617]: DEBUG: <core> [parser/msg_parser.c:170]:
get_hdr_field(): get_hdr_field: cseq <CSeq>: <102> <BYE>
Sep 16 18:49:50 centos k[28617]: DEBUG: <core> [parser/msg_parser.c:204]:
get_hdr_field(): DEBUG: get_hdr_body : content_length=0
Sep 16 18:49:50 centos k[28617]: DEBUG: <core> [parser/msg_parser.c:106]:
get_hdr_field(): found end of header
Sep 16 18:49:50 centos k[28617]: DEBUG: pv [pv_core.c:385]: pv_get_contact(): no contact
header!
Sep 16 18:49:50 centos k[28617]: INFO: <script>: [2] BYE
sip:4165552222@192.168.2.97:5064 From:sip:1234@192.168.2.62,tag=as0f39dff6
To:sip:4165552222@192.168.2.62,tag=d0da9d2543fc82fco4
Call-ID:d0d61319-383c6598@192.168.2.97 Contact:<null>
<192.168.2.2:5060->udp:192.168.2.62:5060>
Sep 16 18:49:50 centos k[28617]: DEBUG: maxfwd [mf_funcs.c:85]: is_maxfwd_present(): value
= 70
Sep 16 18:49:50 centos k[28617]: DEBUG: siputils [checks.c:106]: has_totag(): totag found
Sep 16 18:49:50 centos k[28617]: DEBUG: rr [loose.c:90]: is_preloaded(): is_preloaded: No
Sep 16 18:49:50 centos k[28617]: DEBUG: <core> [socket_info.c:583]:
grep_sock_info(): grep_sock_info - checking if host==us: 12==12 && [192.168.2.97]
== [192.168.2.62]
Sep 16 18:49:50 centos k[28617]: DEBUG: <core> [socket_info.c:587]:
grep_sock_info(): grep_sock_info - checking if port 5060 (advertise 0) matches port 5064
Sep 16 18:49:50 centos k[28617]: DEBUG: <core> [socket_info.c:583]:
grep_sock_info(): grep_sock_info - checking if host==us: 12==12 && [192.168.2.97]
== [192.168.2.62]
Sep 16 18:49:50 centos k[28617]: DEBUG: <core> [socket_info.c:587]:
grep_sock_info(): grep_sock_info - checking if port 8080 (advertise 0) matches port 5064
Sep 16 18:49:50 centos k[28617]: DEBUG: <core> [forward.c:454]: check_self():
check_self: host != me
Sep 16 18:49:50 centos k[28617]: DEBUG: <core> [socket_info.c:583]:
grep_sock_info(): grep_sock_info - checking if host==us: 12==12 && [192.168.2.62]
== [192.168.2.62]
Sep 16 18:49:50 centos k[28617]: DEBUG: <core> [socket_info.c:587]:
grep_sock_info(): grep_sock_info - checking if port 5060 (advertise 0) matches port 5060
Sep 16 18:49:50 centos k[28617]: DEBUG: rr [loose.c:785]: after_loose(): Topmost route
URI: 'sip:192.168.2.62;lr;ftag=d0da9d2543fc82fco4;did=10c.b9a' is me
Sep 16 18:49:50 centos k[28617]: DEBUG: <core> [parser/msg_parser.c:106]:
get_hdr_field(): found end of header
Sep 16 18:49:50 centos k[28617]: DEBUG: rr [loose.c:181]: find_next_route(): No next Route
HF found
Sep 16 18:49:50 centos k[28617]: DEBUG: rr [loose.c:809]: after_loose(): No next URI
found
Sep 16 18:49:50 centos k[28617]: DEBUG: rr [rr_cb.c:97]: run_rr_callbacks(): callback id 0
entered with <lr;ftag=d0da9d2543fc82fco4;did=10c.b9a>
Sep 16 18:49:50 centos k[28617]: DEBUG: dialog [dlg_handlers.c:1163]: dlg_onroute(): route
param is '10c.b9a' (len=7)
Sep 16 18:49:50 centos k[28617]: DEBUG: dialog [dlg_hash.c:654]: dlg_lookup(): ref dlg
0x7ffd35cf9070 with 1 -> 5
Sep 16 18:49:50 centos k[28617]: DEBUG: dialog [dlg_hash.c:656]: dlg_lookup(): dialog
id=2715 found on entry 3073
Sep 16 18:49:50 centos k[28617]: DEBUG: dialog [dlg_profile.c:511]: set_current_dialog():
setting current dialog [3073:2715]
Sep 16 18:49:50 centos k[28617]: DEBUG: dialog [dlg_hash.c:1066]: next_state_dlg(): dialog
0x7ffd35cf9070 changed from state 5 to state 5, due event 7 (ref 5)
Sep 16 18:49:50 centos k[28617]: DEBUG: dialog [dlg_hash.c:872]: dlg_unref(): unref dlg
0x7ffd35cf9070 with 1 -> 4
Sep 16 18:49:50 centos k[28617]: DEBUG: tm [t_lookup.c:1373]: t_newtran(): DEBUG:
t_newtran: msg id=2 , global msg id=0 , T on entrance=0xffffffffffffffff
Sep 16 18:49:50 centos k[28617]: DEBUG: tm [t_lookup.c:527]: t_lookup_request():
t_lookup_request: start searching: hash=15057, isACK=0
Sep 16 18:49:50 centos k[28617]: DEBUG: tm [t_lookup.c:485]: matching_3261(): DEBUG:
RFC3261 transaction matching failed
Sep 16 18:49:50 centos k[28617]: DEBUG: tm [t_lookup.c:709]: t_lookup_request(): DEBUG:
t_lookup_request: no transaction found
Sep 16 18:49:50 centos k[28617]: DEBUG: tm [t_hooks.c:374]:
run_reqin_callbacks_internal(): DBG: trans=0x7ffd35cf9320, callback type 1, id 0 entered
Sep 16 18:49:50 centos k[28617]: DEBUG: tm [t_hooks.c:374]:
run_reqin_callbacks_internal(): DBG: trans=0x7ffd35cf9320, callback type 1, id 0 entered
Sep 16 18:49:50 centos k[28617]: DEBUG: <core> [md5utils.c:67]: MD5StringArray():
DEBUG: MD5 calculated: 159d78ac3eb576dff3365fffb4d172d7
Sep 16 18:49:50 centos k[28617]: DEBUG: <core> [msg_translator.c:205]:
check_via_address(): check_via_address(192.168.2.2, 192.168.2.2, 0)
Sep 16 18:49:50 centos k[28617]: DEBUG: tm [t_funcs.c:394]: t_relay_to(): SER: new
transaction fwd'ed
Sep 16 18:49:50 centos k[28617]: DEBUG: dialog [dlg_hash.c:654]: dlg_lookup(): ref dlg
0x7ffd35cf9070 with 1 -> 5
Sep 16 18:49:50 centos k[28617]: DEBUG: dialog [dlg_hash.c:656]: dlg_lookup(): dialog
id=2715 found on entry 3073
Sep 16 18:49:50 centos k[28617]: DEBUG: dialog [dlg_hash.c:872]: dlg_unref(): unref dlg
0x7ffd35cf9070 with 1 -> 4
Sep 16 18:49:50 centos k[28617]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
Sep 16 18:49:50 centos k[28617]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
Sep 16 18:49:50 centos k[28617]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
Sep 16 18:49:50 centos k[28617]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
Sep 16 18:49:50 centos k[28617]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
Sep 16 18:49:50 centos k[28617]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
Sep 16 18:49:50 centos k[28617]: DEBUG: <core> [xavp.c:448]: xavp_destroy_list():
destroying xavp list (nil)
Sep 16 18:49:50 centos k[28617]: DEBUG: <core> [receive.c:300]: receive_msg():
receive_msg: cleaning up
Sep 16 18:49:50 centos k[28618]: DEBUG: <core> [parser/msg_parser.c:633]:
parse_msg(): SIP Reply (status):
Sep 16 18:49:50 centos k[28618]: DEBUG: <core> [parser/msg_parser.c:635]:
parse_msg(): version: <SIP/2.0>
Sep 16 18:49:50 centos k[28618]: DEBUG: <core> [parser/msg_parser.c:637]:
parse_msg(): status: <200>
Sep 16 18:49:50 centos k[28618]: DEBUG: <core> [parser/msg_parser.c:639]:
parse_msg(): reason: <OK>
Sep 16 18:49:50 centos k[28618]: DEBUG: <core> [parser/parse_addr_spec.c:176]:
parse_to_param(): DEBUG: add_param: tag=d0da9d2543fc82fco4
Sep 16 18:49:50 centos k[28618]: DEBUG: <core> [parser/parse_addr_spec.c:898]:
parse_addr_spec(): end of header reached, state=29
Sep 16 18:49:50 centos k[28618]: DEBUG: <core> [parser/msg_parser.c:190]:
get_hdr_field(): DEBUG: get_hdr_field: <To> [54]; uri=[sip:4165552222@192.168.2.62]
Sep 16 18:49:50 centos k[28618]: DEBUG: <core> [parser/msg_parser.c:192]:
get_hdr_field(): DEBUG: to body [<sip:4165552222@192.168.2.62>]
Sep 16 18:49:50 centos k[28618]: DEBUG: <core> [parser/msg_parser.c:170]:
get_hdr_field(): get_hdr_field: cseq <CSeq>: <102> <BYE>
Sep 16 18:49:50 centos k[28618]: DEBUG: <core> [parser/parse_via.c:1284]:
parse_via_param(): Found param type 232, <branch> =
<z9hG4bK1da3.159d78ac3eb576dff3365fffb4d172d7.0>; state=16
Sep 16 18:49:50 centos k[28618]: DEBUG: <core> [parser/parse_via.c:2672]:
parse_via(): end of header reached, state=5
Sep 16 18:49:50 centos k[28618]: DEBUG: <core> [parser/msg_parser.c:513]:
parse_headers(): parse_headers: Via found, flags=2
Sep 16 18:49:50 centos k[28618]: DEBUG: <core> [parser/msg_parser.c:515]:
parse_headers(): parse_headers: this is the first via
Sep 16 18:49:50 centos k[28618]: DEBUG: <core> [receive.c:154]: receive_msg(): After
parse_msg...
Sep 16 18:49:50 centos k[28618]: DEBUG: tm [t_lookup.c:1072]: t_check_msg(): DEBUG:
t_check_msg: msg id=3 global id=2 T start=0xffffffffffffffff
Sep 16 18:49:50 centos k[28618]: DEBUG: tm [t_lookup.c:949]: t_reply_matching(): DEBUG:
t_reply_matching: hash 15057 label 0 branch 0
Sep 16 18:49:50 centos k[28618]: DEBUG: tm [t_lookup.c:1004]: t_reply_matching(): DEBUG:
t_reply_matching: reply matched (T=0x7ffd35cf9320)!
Sep 16 18:49:50 centos k[28618]: DEBUG: tm [t_hooks.c:288]:
run_trans_callbacks_internal(): DBG: trans=0x7ffd35cf9320, callback type 2, id 0 entered
Sep 16 18:49:50 centos k[28618]: DEBUG: dialog [dlg_hash.c:654]: dlg_lookup(): ref dlg
0x7ffd35cf9070 with 1 -> 5
Sep 16 18:49:50 centos k[28618]: DEBUG: dialog [dlg_hash.c:656]: dlg_lookup(): dialog
id=2715 found on entry 3073
Sep 16 18:49:50 centos k[28618]: DEBUG: dialog [dlg_profile.c:511]: set_current_dialog():
setting current dialog [3073:2715]
Sep 16 18:49:50 centos k[28618]: DEBUG: dialog [dlg_hash.c:872]: dlg_unref(): unref dlg
0x7ffd35cf9070 with 1 -> 4
Sep 16 18:49:50 centos k[28618]: DEBUG: tm [t_lookup.c:1141]: t_check_msg(): DEBUG:
t_check_msg: msg id=3 global id=3 T end=0x7ffd35cf9320
Sep 16 18:49:50 centos k[28618]: DEBUG: tm [t_reply.c:2210]: reply_received(): DEBUG:
reply_received: org. status uas=0, uac[0]=0 local=0 is_invite=0)
Sep 16 18:49:50 centos k[28618]: INFO: <script>: [3] entering onreply_route[BYE] for
200 OK Call-ID:d0d61319-383c6598@192.168.2.97 Cseq:102
Sep 16 18:49:50 centos k[28618]: INFO: <script>: [3] exiting onreply_route[BYE] for
200 OK Call-ID:d0d61319-383c6598@192.168.2.97 Cseq:102
Sep 16 18:49:50 centos k[28618]: DEBUG: tm [t_reply.c:1304]: t_should_relay_response():
->>>>>>>>> T_code=0, new_code=200
Sep 16 18:49:50 centos k[28618]: DEBUG: tm [t_reply.c:1822]: relay_reply(): DEBUG:
relay_reply: branch=0, save=0, relay=0 icode=0
Sep 16 18:49:50 centos k[28618]: DEBUG: <core> [msg_translator.c:2305]:
generate_res_buf_from_sip_res(): old size: 468, new size: 383
Sep 16 18:49:50 centos k[28618]: DEBUG: <core> [msg_translator.c:2323]:
generate_res_buf_from_sip_res(): copied size: orig:261, new: 176, rest: 207
msg=#012SIP/2.0 200 OK#015#012To:
<sip:4165552222@192.168.2.62>;tag=d0da9d2543fc82fco4#015#012From:
<sip:1234@192.168.2.62>;tag=as0f39dff6#015#012Call-ID:
d0d61319-383c6598(a)192.168.2.97#015#012CSeq: 102 BYE#015#012Via: SIP/2.0/UDP
192.168.2.2:5060;branch=z9hG4bK72762b8e;rport=5060#015#012Server:
Linksys/SPA962-6.1.5(a)#015#012P-RTP-Stat:
PS=615,OS=98400,PR=585,OR=93600,PL=0,JI=0,LA=0,DU=12,EN=G711u,DE=G711u#015#012Content-Length:
0#015#012#015#012
Sep 16 18:49:50 centos k[28618]: DEBUG: <core> [mem/shm_mem.c:111]: _shm_resize():
WARNING:vqm_resize: resize(0) called
Sep 16 18:49:50 centos k[28618]: DEBUG: tm [t_reply.c:1663]: cleanup_uac_timers(): DEBUG:
cleanup_uac_timers: RETR/FR timers reset
Sep 16 18:49:50 centos k[28618]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
Sep 16 18:49:50 centos k[28618]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
Sep 16 18:49:50 centos k[28618]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
Sep 16 18:49:50 centos k[28618]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
Sep 16 18:49:50 centos k[28618]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
Sep 16 18:49:50 centos k[28618]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
Sep 16 18:49:50 centos k[28618]: DEBUG: <core> [xavp.c:448]: xavp_destroy_list():
destroying xavp list (nil)
Sep 16 18:49:50 centos k[28618]: DEBUG: <core> [receive.c:300]: receive_msg():
receive_msg: cleaning up
Sep 16 18:49:50 centos k[28616]: DEBUG: <core> [parser/msg_parser.c:623]:
parse_msg(): SIP Request:
Sep 16 18:49:50 centos k[28616]: DEBUG: <core> [parser/msg_parser.c:625]:
parse_msg(): method: <NOTIFY>
Sep 16 18:49:50 centos k[28616]: DEBUG: <core> [parser/msg_parser.c:627]:
parse_msg(): uri: <sip:192.168.2.62>
Sep 16 18:49:50 centos k[28616]: DEBUG: <core> [parser/msg_parser.c:629]:
parse_msg(): version: <SIP/2.0>
Sep 16 18:49:50 centos k[28616]: DEBUG: <core> [parser/parse_via.c:1284]:
parse_via_param(): Found param type 232, <branch> = <z9hG4bK-cc90acfe>;
state=16
Sep 16 18:49:50 centos k[28616]: DEBUG: <core> [parser/parse_via.c:2672]:
parse_via(): end of header reached, state=5
Sep 16 18:49:50 centos k[28616]: DEBUG: <core> [parser/msg_parser.c:513]:
parse_headers(): parse_headers: Via found, flags=2
Sep 16 18:49:50 centos k[28616]: DEBUG: <core> [parser/msg_parser.c:515]:
parse_headers(): parse_headers: this is the first via
Sep 16 18:49:50 centos k[28616]: DEBUG: <core> [receive.c:154]: receive_msg(): After
parse_msg...
Sep 16 18:49:50 centos k[28616]: DEBUG: <core> [receive.c:197]: receive_msg():
preparing to run routing scripts...
Sep 16 18:49:50 centos k[28616]: DEBUG: <core> [parser/parse_addr_spec.c:898]:
parse_addr_spec(): end of header reached, state=10
Sep 16 18:49:50 centos k[28616]: DEBUG: <core> [parser/msg_parser.c:190]:
get_hdr_field(): DEBUG: get_hdr_field: <To> [20]; uri=[sip:192.168.2.62]
Sep 16 18:49:50 centos k[28616]: DEBUG: <core> [parser/msg_parser.c:192]:
get_hdr_field(): DEBUG: to body [<sip:192.168.2.62>#015#012]
Sep 16 18:49:50 centos k[28616]: DEBUG: <core> [parser/msg_parser.c:170]:
get_hdr_field(): get_hdr_field: cseq <CSeq>: <265193> <NOTIFY>
Sep 16 18:49:50 centos k[28616]: DEBUG: <core> [parser/msg_parser.c:204]:
get_hdr_field(): DEBUG: get_hdr_body : content_length=0
Sep 16 18:49:50 centos k[28616]: DEBUG: <core> [parser/msg_parser.c:106]:
get_hdr_field(): found end of header
Sep 16 18:49:50 centos k[28616]: DEBUG: <core> [socket_info.c:583]:
grep_sock_info(): grep_sock_info - checking if host==us: 12==12 && [192.168.2.62]
== [192.168.2.62]
Sep 16 18:49:50 centos k[28616]: DEBUG: <core> [socket_info.c:587]:
grep_sock_info(): grep_sock_info - checking if port 5060 (advertise 0) matches port 5060
Sep 16 18:49:50 centos k[28616]: DEBUG: <core> [msg_translator.c:205]:
check_via_address(): check_via_address(192.168.2.97, 192.168.2.97, 0)
Sep 16 18:49:50 centos k[28616]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
Sep 16 18:49:50 centos k[28616]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
Sep 16 18:49:50 centos k[28616]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
Sep 16 18:49:50 centos k[28616]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
Sep 16 18:49:50 centos k[28616]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
Sep 16 18:49:50 centos k[28616]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
Sep 16 18:49:50 centos k[28616]: DEBUG: <core> [xavp.c:448]: xavp_destroy_list():
destroying xavp list (nil)
Sep 16 18:49:50 centos k[28616]: DEBUG: <core> [receive.c:300]: receive_msg():
receive_msg: cleaning up
Sep 16 18:49:51 centos k[28620]: INFO: <script>: [2] exiting
event_route[dialog:end]
Sep 16 18:49:51 centos k[28620]: DEBUG: dialog [dlg_hash.c:872]: dlg_unref(): unref dlg
0x7ffd35cf9070 with 1 -> 3
Sep 16 18:49:51 centos k[28620]: DEBUG: dialog [dlg_hash.c:854]: dlg_ref(): ref dlg
0x7ffd35cf9070 with 1 -> 4
Sep 16 18:49:51 centos k[28620]: DEBUG: dialog [dlg_handlers.c:1285]: dlg_onroute(): BYE
successfully processed
Sep 16 18:49:51 centos k[28620]: DEBUG: dialog [dlg_hash.c:872]: dlg_unref(): unref dlg
0x7ffd35cf9070 with 2 -> 2
Sep 16 18:49:51 centos k[28620]: DEBUG: dialog [dlg_hash.c:872]: dlg_unref(): unref dlg
0x7ffd35cf9070 with 1 -> 1
Sep 16 18:49:51 centos k[28620]: DEBUG: tm [t_lookup.c:1373]: t_newtran(): DEBUG:
t_newtran: msg id=2 , global msg id=1 , T on entrance=0xffffffffffffffff
Sep 16 18:49:51 centos k[28620]: DEBUG: tm [t_lookup.c:527]: t_lookup_request():
t_lookup_request: start searching: hash=15057, isACK=0
Sep 16 18:49:51 centos k[28620]: DEBUG: tm [t_lookup.c:470]: matching_3261(): DEBUG:
RFC3261 transaction matched, tid=72762b8e
Sep 16 18:49:51 centos k[28620]: DEBUG: tm [t_lookup.c:726]: t_lookup_request(): DEBUG:
t_lookup_request: transaction found (T=0x7ffd35cf9320)
Sep 16 18:49:51 centos k[28620]: DEBUG: tm [t_reply.c:1623]: t_retransmit_reply(): DEBUG:
reply retransmitted. buf=0x7ffd30ab97a0: SIP/2.0 2..., shmem=0x7ffd35cfca68: SIP/2.0 2
Sep 16 18:49:51 centos k[28620]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
Sep 16 18:49:51 centos k[28620]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
Sep 16 18:49:51 centos k[28620]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
Sep 16 18:49:51 centos k[28620]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
Sep 16 18:49:51 centos k[28620]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
Sep 16 18:49:51 centos k[28620]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
Sep 16 18:49:51 centos k[28620]: DEBUG: <core> [xavp.c:448]: xavp_destroy_list():
destroying xavp list (nil)
Sep 16 18:49:51 centos k[28620]: DEBUG: <core> [receive.c:300]: receive_msg():
receive_msg: cleaning up
Sep 16 18:49:55 centos k[28622]: DEBUG: dialog [dlg_handlers.c:324]: dlg_iuid_sfree():
freeing dlg iuid [3073:2715] (0x7ffd35cfbd68)
$ kamcmd dlg.list
{
h_entry: 3073
h_id: 2715
call-id: d0d61319-383c6598(a)192.168.2.97
from_uri: sip:4165552222@192.168.2.62
to_uri: sip:1234@192.168.2.62
state: 5
start_ts: 1410907778
init_ts: 1410907775
timeout: 0
lifetime: 3600
dflags: 519
sflags: 0
iflags: 1
caller: {
tag: d0da9d2543fc82fco4
contact: sip:4165552222@192.168.2.97:5064
cseq: 101
route_set:
socket: udp:192.168.2.62:5060
}
callee: {
tag: as0f39dff6
contact: sip:240@192.168.2.2:5060
cseq: 0
route_set:
socket: udp:192.168.2.62:5060
}
profiles: {
}
variables: {
}
}
----------
More information can be found at the following URL:
http://sip-router.org/tracker/index.php?do=details&task_id=424#comment1…
You are receiving this message because you have requested it from the Flyspray bugtracking
system. If you did not expect this message or don't want to receive mails in future,
you can change your notification settings at the URL shown above.
3724
days inactive
3724
days old
0 comments
1 participants
participants (1)
-
sip-router