[OpenSIPS-Users] miss BYE

Nick nick_chang at ezmobo.com
Wed Dec 14 08:26:44 CET 2011 

  Hello

It's my debug log for opensips.
I don't know why. I missed bye for callee or caller.
If everyone can give me a suggest.
Thanks

Nick
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26661]: 
> DBG:registrar:build_contact: created Contact HF: Contact: 
> <sip:2 at 192.168.20.126:57191;transport=udp>;expires=2383;received="sip:220.130.6.180:57191", 
> <sip:2 at 192.168.20.126:55541;transport=udp>;expires=3200;received="sip:220.130.6.180:55541"^M
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26661]: 
> DBG:core:parse_headers: flags=ffffffffffffffff
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26661]: 
> DBG:sl:run_sl_callbacks: callback id 0 entered
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26661]: 
> DBG:siptrace:trace_sl_onreply_out: nothing to trace...
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26661]: 
> DBG:core:destroy_avp_list: destroying list 0xb60dba34
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26661]: 
> DBG:core:receive_msg: cleaning up
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:parse_msg: SIP Request:
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:parse_msg:  method: <BYE>
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:parse_msg:  uri: 
> <sip:5 at 220.130.6.180:56382;transport=udp;nat=yes>
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:parse_msg:  version: <SIP/2.0>
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:parse_headers: flags=2
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:parse_via_param: found param type 232, <branch> = 
> <z9hG4bK-d8754z-f8142f691a5bab3f-1---d8754z->; state=6
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:parse_via_param: found param type 235, <rport> = <n/a>; state=17
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:parse_via: end of header reached, state=5
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:parse_headers: via found, flags=2
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:parse_headers: this is the first via
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:receive_msg: After parse_msg...
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:receive_msg: preparing to run routing scripts...
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:parse_headers: flags=10
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:parse_to_param: tag=711628967
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:parse_to: end of header reached, state=29
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:parse_to: display={"5"}, ruri={sip:5 at 220.130.6.180}
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:get_hdr_field: <To> [40]; uri=[sip:5 at 220.130.6.180]
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:get_hdr_field: to body ["5"<sip:5 at 220.130.6.180>]
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:parse_to_param: tag=842eca09
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:parse_to: end of header reached, state=29
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:parse_to: display={"test"}, ruri={sip:999 at 220.130.6.180}
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: ROUTE 
> BEGIN sip:999 at 220.130.6.180
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:maxfwd:is_maxfwd_present: value = 70
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:check_ip_address: params 192.168.20.138, 192.168.20.138, 0
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:parse_headers: flags=ffffffffffffffff
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:get_hdr_field: cseq <CSeq>: <3> <BYE>
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:get_hdr_field: content_length=0
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:get_hdr_field: found end of header
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:uri:has_totag: totag found
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:parse_headers: flags=200
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:rr:is_preloaded: is_preloaded: No
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:grep_sock_info: checking if host==us: 13==9 &&  
> [220.130.6.180] == [127.0.0.1]
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:grep_sock_info: checking if port 5060 matches port 56382
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:grep_sock_info: checking if host==us: 13==14 &&  
> [220.130.6.180] == [192.168.20.118]
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:grep_sock_info: checking if port 5060 matches port 56382
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:grep_sock_info: checking if host==us: 13==9 &&  
> [220.130.6.180] == [127.0.0.1]
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:grep_sock_info: checking if port 5060 matches port 56382
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:grep_sock_info: checking if host==us: 13==14 &&  
> [220.130.6.180] == [192.168.20.118]
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:grep_sock_info: checking if port 5060 matches port 56382
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:rr:after_strict: Next hop: 
> 'sip:192.168.20.118;lr;did=2bb.5ff88246' is loose router
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:parse_headers: flags=ffffffffffffffff
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:rr:after_strict: The last route URI: 
> 'sip:192.168.20.118;lr;did=2bb.5ff88246'
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:rr:run_rr_callbacks: callback id 1 entered with 
> <transport=udp;nat=yes>
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:dialog:dlg_onroute: Route param 'did' not found
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:parse_headers: flags=58
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:dialog:get_dlg: input 
> ci=<YjUyMTY5NzY4MTA3MTU3NWUxOWJiODkyYTdlNzM4MDQ.>(44), 
> tt=<842eca09>(8), ft=<711628967>(9)
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:dialog:get_dlg: no dialog 
> callid='YjUyMTY5NzY4MTA3MTU3NWUxOWJiODkyYTdlNzM4MDQ.' found
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:dialog:dlg_onroute: Callid 
> 'YjUyMTY5NzY4MTA3MTU3NWUxOWJiODkyYTdlNzM4MDQ.' not found
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: ROUTE 1 
> sip:999 at 220.130.6.180
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:subst_run: running. r=1
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:subst_str: no match
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:tm:t_newtran: transaction on entrance=0xffffffff
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:parse_headers: flags=ffffffffffffffff
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:parse_headers: flags=78
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:tm:t_lookup_request: start searching: hash=19431, isACK=0
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:tm:matching_3261: RFC3261 transaction matching failed
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:tm:t_lookup_request: no transaction found
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:tm:run_reqin_callbacks: trans=0xb60e1a24, callback type 1, id 2 
> entered
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:siptrace:trace_onreq_in: nothing to trace...
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:tm:run_reqin_callbacks: trans=0xb60e1a24, callback type 1, id 1 
> entered
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:tm:run_reqin_callbacks: trans=0xb60e1a24, callback type 1, id 0 
> entered
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:parse_headers: flags=78
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:_shm_resize: resize(0) called
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:mk_proxy: doing DNS lookup...
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:tm:set_timer: relative timeout is 500000
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:core:parse_msg: SIP Request:
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:tm:insert_timer_unsafe: [4]: 0xb60e1b70 (923900000)
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:core:parse_msg:  method: <BYE>
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:tm:set_timer: relative timeout is 5
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:core:parse_msg:  uri: <sip:192.168.20.118;lr;did=2bb.5ff88246>
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:tm:insert_timer_unsafe: [0]: 0xb60e1b8c (928)
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:core:parse_msg:  version: <SIP/2.0>
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:tm:t_relay_to: new transaction fwd'ed
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:core:parse_headers: flags=2
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:tm:t_unref: UNREF_UNSAFE: [0xb60e1a24] after is 0
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:core:parse_via_param: found param type 232, <branch> = 
> <z9hG4bK7eb4.65002b42.0>; state=16
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:destroy_avp_list: destroying list (nil)
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:core:parse_via: end of header reached, state=5
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26663]: 
> DBG:core:receive_msg: cleaning up
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:core:parse_headers: via found, flags=2
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:core:parse_headers: this is the first via
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:core:receive_msg: After parse_msg...
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:core:receive_msg: preparing to run routing scripts...
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:core:parse_headers: flags=10
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:core:parse_via_param: found param type 234, <received> = 
> <192.168.20.138>; state=6
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:core:parse_via_param: found param type 232, <branch> = 
> <z9hG4bK-d8754z-f8142f691a5bab3f-1---d8754z->; state=6
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:core:parse_via_param: found param type 235, <rport> = <35866>; 
> state=16
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:core:parse_via: end of header reached, state=5
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:core:parse_headers: via found, flags=10
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:core:parse_headers: parse_headers: this is the second via
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:core:parse_to_param: tag=711628967
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:core:parse_to: end of header reached, state=29
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:core:parse_to: display={"5"}, ruri={sip:5 at 220.130.6.180}
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:core:get_hdr_field: <To> [40]; uri=[sip:5 at 220.130.6.180]
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:core:get_hdr_field: to body ["5"<sip:5 at 220.130.6.180>]
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:core:parse_to_param: tag=842eca09
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:core:parse_to: end of header reached, state=29
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:core:parse_to: display={"test"}, ruri={sip:999 at 220.130.6.180}
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: ROUTE 
> BEGIN sip:999 at 220.130.6.180
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:maxfwd:is_maxfwd_present: value = 69
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:core:check_ip_address: params 192.168.20.118, 192.168.20.118, 0
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:core:parse_headers: flags=ffffffffffffffff
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:core:get_hdr_field: cseq <CSeq>: <3> <BYE>
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:core:get_hdr_field: content_length=0
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:core:get_hdr_field: found end of header
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:uri:has_totag: totag found
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:core:parse_headers: flags=200
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:rr:find_first_route: No Route headers found
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:rr:loose_route: There is no Route HF
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:core:parse_headers: flags=ffffffffffffffff
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:sl:run_sl_callbacks: callback id 0 entered
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:siptrace:trace_sl_onreply_out: nothing to trace...
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:core:destroy_avp_list: destroying list 0xb60dd2cc
> Dec 14 14:48:16 sfs-staging /usr/local/sbin/opensips[26665]: 
> DBG:core:parse_msg: SIP Reply  (status):
> Dec 14 14:48:17 sfs-staging /usr/local/sbin/opensips[26660]: 
> DBG:core:receive_msg: cleaning up
> Dec 14 14:48:17 sfs-staging /usr/local/sbin/opensips[26665]: 
> DBG:core:parse_msg:  version: <SIP/2.0>
> Dec 14 14:48:17 sfs-staging /usr/local/sbin/opensips[26665]: 
> DBG:core:parse_msg:  status: <404>
> Dec 14 14:48:17 sfs-staging /usr/local/sbin/opensips[26665]: 
> DBG:core:parse_msg:  reason: <Not here>
> Dec 14 14:48:17 sfs-staging /usr/local/sbin/opensips[26665]: 
> DBG:core:parse_headers: flags=2
> Dec 14 14:48:17 sfs-staging /usr/local/sbin/opensips[26665]: 
> DBG:core:parse_via_param: found param type 234, <received> = 
> <192.168.20.118>; state=6
> Dec 14 14:48:17 sfs-staging /usr/local/sbin/opensips[26665]: 
> DBG:core:parse_via_param: found param type 235, <rport> = <5060>; state=6
> Dec 14 14:48:17 sfs-staging /usr/local/sbin/opensips[26665]: 
> DBG:core:parse_via_param: found param type 232, <branch> = 
> <z9hG4bK7eb4.65002b42.0>; state=16
> Dec 14 14:48:17 sfs-staging /usr/local/sbin/opensips[26665]: 
> DBG:core:parse_via: end of header reached, state=5
> Dec 14 14:48:17 sfs-staging /usr/local/sbin/opensips[26665]: 
> DBG:core:parse_headers: via found, flags=2

More information about the Users mailing list