>Hi,

>if it is a single one, it may be delayed reply to the BYE request and to
>have a race between firing the first retransmission and receiving the
>reply (as maybe both events are very close in time).

>Do you have a trace with timestamps also?

>Regards,
>Bogdan

Hi,
this is a part of the syslog with parameter debug=7.

Jan 14 10:04:23 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_msg: SIP Request:
Jan 14 10:04:23 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_msg:  method:  <BYE>
Jan 14 10:04:23 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_msg:  uri:     <sip:[email protected]:1024>
Jan 14 10:04:23 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_msg:  version: <SIP/2.0>
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_headers: flags=2
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_via_param: found param type 235, <rport> = <n/a>; state=6
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_via_param: found param type 232, <branch> = 
<z9hG4bK0a0a2d4e00000023496db628368fa1040000002e>; state=16
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_via: end of header reached, state=5
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_headers: via found, flags=2
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_headers: this is the first via
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:receive_msg: After parse_msg...
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:receive_msg: preparing to run routing scripts...
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_headers: flags=10
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:get_hdr_field: content_length=0
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:get_hdr_field: cseq <CSeq>: <1> <BYE>
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_to_param: tag=35661671621893720533
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: DBG:core:parse_to: 
end of header reached, state=29
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: DBG:core:parse_to: 
display={"SJphone User"}, ruri={sip:[email protected]}
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_headers: flags=8
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_to_param: tag=356629413371487987
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: DBG:core:parse_to: 
end of header reached, state=29
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: DBG:core:parse_to: 
display={}, ruri={sip:[email protected]}
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:get_hdr_field: <To> [45]; uri=[sip:[email protected]]
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:get_hdr_field: to body [<sip:[email protected]>]
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: New request - 
M=BYE RURI=sip:[email protected]:1024 F=sip:[email protected] T=sip:[email protected] 
IP=10.10.45.78 [email protected]
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_headers: flags=40
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:siptrace:sip_trace: storing info...
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:maxfwd:is_maxfwd_present: value = 70
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: DBG:uri:has_totag: 
totag found
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_headers: flags=200
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:rr:is_preloaded: is_preloaded: No
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:grep_sock_info: checking if host==us: 12==12 &&  [10.10.45.102] == 
[10.10.45.158]
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:grep_sock_info: checking if port 5060 matches port 1024
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:check_self: host != me
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:grep_sock_info: checking if host==us: 12==12 &&  [10.10.45.158] == 
[10.10.45.158]
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:grep_sock_info: checking if port 5060 matches port 5060
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:rr:after_loose: Topmost route URI: 
'sip:10.10.45.158;lr=on;ftag=356629413371487987' is me
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_headers: flags=200
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:get_hdr_field: found end of header
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:rr:find_next_route: No next Route HF found
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:rr:after_loose: No next URI found
Jan 14 10:04:24 opensips-lab media-dispatcher[2833]: 
[OpenSIPSControlProtocol,14,] Issuing "remove" command to relay at 10.10.45.158
Jan 14 10:04:24 opensips-lab media-relay[2842]: [RelayClientProtocol,client] 
removing session [email protected]: 
[email protected] (356629413371487987) --> [email protected]
Jan 14 10:04:24 opensips-lab media-relay[2842]: [-] (Port 50024 Closed)
Jan 14 10:04:24 opensips-lab media-relay[2842]: [-] (Port 50025 Closed)
Jan 14 10:04:24 opensips-lab media-relay[2842]: [-] (Port 50026 Closed)
Jan 14 10:04:24 opensips-lab media-relay[2842]: [-] (Port 50027 Closed)
Jan 14 10:04:24 opensips-lab media-dispatcher[2833]: 
[RelayServerProtocol,0,10.10.45.158] Got statistics: {'from_tag': 
'356629413371487987', 'dialog_id': None, 'start_time': 1231923857.6600001, 
'timed_out': False, 'call_id': 
'[email protected]', 'to_tag': 
'35661671621893720533', 'streams': [{'status': 'closed', 'caller_codec': 'GSM', 
'post_dial_delay': 2.6055760383600002, 'callee_codec': 'GSM', 'start_time': 0, 
'caller_bytes': 23944, 'callee_bytes': 23579, 'caller_packets': 328, 
'end_time': 6, 'callee_remote': '10.10.45.78:49154', 'caller_remote': 
'10.10.45.102:49152', 'media_type': 'audio', 'callee_local': 
'10.10.45.158:50026', 'timeout_wait': 0, 'caller_local': '10.10.45.158:50024', 
'callee_packets': 323}], 'duration': 6, 'to_uri': '[email protected]', 'from_uri': 
'[email protected]', 'callee_ua': 'SJphone/1.60.299a/L (SJ Labs)', 'caller_ua': 
'SJphone/1.60.299a/L (SJ Labs)'}
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: DBG:tm:t_newtran: 
transaction on entrance=0xffffffff
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_headers: flags=ffffffffffffffff
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_headers: flags=78
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:tm:t_lookup_request: start searching: hash=8608, isACK=0
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:tm:matching_3261: RFC3261 transaction matching failed
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:tm:t_lookup_request: no transaction found
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:tm:run_reqin_callbacks: trans=0xb5bc5698, callback type 1, id 1 entered
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_headers: flags=40
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:tm:run_reqin_callbacks: trans=0xb5bc5698, callback type 1, id 0 entered
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_headers: flags=78
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: DBG:acc:acc_onreq: 
detected an UPSTREAM req -> flaging it
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: DBG:core:mk_proxy: 
doing DNS lookup...
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:tm:run_trans_callbacks: trans=0xb5bc5698, callback type 1024, id 0 entered
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:parse_msg: SIP Reply  (status):
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:parse_msg:  version: <SIP/2.0>
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:parse_msg:  status:  <200>
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:parse_msg:  reason:  <OK>
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:parse_headers: flags=2
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:parse_via_param: found param type 232, <branch> = 
<z9hG4bK0a12.d34802f2.0>; state=9
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:parse_via: next_via
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:parse_via_param: found param type 235, <rport> = <5060>; state=6
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:parse_via_param: found param type 234, <received> = <10.10.45.78>; 
state=6
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:parse_via_param: found param type 232, <branch> = 
<z9hG4bK0a0a2d4e00000023496db628368fa1040000002e>; state=16
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:parse_via: end of header reached, state=5
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:parse_headers: via found, flags=2
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:parse_headers: this is the first via
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:receive_msg: After parse_msg...
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:forward_reply: found module nat_traversal, passing reply to it
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:parse_headers: flags=4
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:forward_reply: found module tm, passing reply to it
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: DBG:tm:t_check: 
start=0xffffffff
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:parse_headers: flags=22
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:get_hdr_field: content_length=0
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:get_hdr_field: cseq <CSeq>: <1> <BYE>
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:tm:t_reply_matching: hash 8608 label 790660157 branch 0
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:tm:t_reply_matching: REF_UNSAFE: after is 2
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:tm:t_reply_matching: reply matched (T=0xb5bc5698)!
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:tm:run_trans_callbacks: trans=0xb5bc5698, callback type 2, id 3 entered
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:parse_headers: flags=8
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:parse_to_param: tag=356629413371487987
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: DBG:core:parse_to: 
end of header reached, state=29
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: DBG:core:parse_to: 
display={"Sjphone laptop_User"}, ruri={sip:[email protected]}
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:get_hdr_field: <To> [66]; uri=[sip:[email protected]]
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:get_hdr_field: to body ["Sjphone laptop_User"<sip:[email protected]>]
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:tm:run_trans_callbacks: trans=0xb5bc5698, callback type 2, id 1 entered
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:parse_to_param: tag=35661671621893720533
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: DBG:core:parse_to: 
end of header reached, state=29
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: DBG:core:parse_to: 
display={"SJphone User"}, ruri={sip:[email protected]}
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:parse_headers: flags=40
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:siptrace:trace_onreply_in: storing info...
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: DBG:tm:t_check: 
end=0xb5bc5698
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:tm:reply_received: org. status uas=0, uac[0]=0 local=0 is_invite=0)
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:tm:t_should_relay_response: T_code=0, new_code=200
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:tm:relay_reply: branch=0, save=0, relay=0
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:build_res_buf_from_sip_res:  old size: 458, new size: 403
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:build_res_buf_from_sip_res: copied size: orig:76, new: 21, rest: 382 
msg= SIP/2.0 200 OK^M Via: SIP/2.0/UDP 
10.10.45.78;rport=5060;received=10.10.45.78;branch=z9hG4bK0a0a2d4e00000023496db628368fa1040000002e^M
 Content-Length: 0^M Call-ID: 
[email protected]^m CSeq: 1 BYE^M From: 
"SJphone User"<sip:[email protected]>;tag=35661671621893720533^M Server: 
SJphone/1.60.299a/L (SJ Labs)^M To: "Sjphone 
laptop_User"<sip:[email protected]>;tag=356629413371487987^M ^M
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:_shm_resize: resize(0) called
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:tm:insert_timer_unsafe: [2]: 0xb5bc56e0 (352)
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:tm:relay_reply: sent buf=0x81b2cd0: SIP/2.0 2..., shmem=0xb5bc4838: SIP/2.0 
2
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:tm:run_trans_callbacks: trans=0xb5bc5698, callback type 128, id 3 entered
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:acc:core2strar: the flag UPSTREAM is set -> swap F/T
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: ACC: transaction 
answered: 
timestamp=1231923864;method=BYE;from_tag=356629413371487987;to_tag=35661671621893720533;[email protected];code=200;reason=OK;caller_id=sip:[email protected];callee_id=sip:[email protected];destination=10.10.45.102
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:acc:core2strar: the flag UPSTREAM is set -> swap F/T
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:tm:run_trans_callbacks: trans=0xb5bc5698, callback type 128, id 2 entered
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:parse_headers: flags=40
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:siptrace:trace_onreply_out: dest [udp:10.10.45.78:5060]
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:siptrace:trace_onreply_out: storing info...
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:tm:cleanup_uac_timers: RETR/FR timers reset
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: DBG:tm:t_unref: 
UNREF_UNSAFE: after is 1
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:destroy_avp_list: destroying list (nil)
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:receive_msg: cleaning up
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_headers: flags=40
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:siptrace:trace_onreq_out: dest [udp:10.10.45.102:1024]
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:siptrace:trace_onreq_out: storing info...
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: DBG:tm:set_timer: 
relative timeout is 500000
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:tm:insert_timer_unsafe: [4]: 0xb5bc57e4 (347700000)
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: DBG:tm:set_timer: 
relative timeout is 30
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:tm:insert_timer_unsafe: [0]: 0xb5bc5800 (377)
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: DBG:tm:t_relay_to: 
new transaction fwd'ed
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: DBG:tm:t_unref: 
UNREF_UNSAFE: after is 0
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:destroy_avp_list: destroying list (nil)
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:receive_msg: cleaning up
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2922]: 
DBG:tm:utimer_routine: timer routine:4,tl=0xb5bc57e4 next=(nil), 
timeout=347700000
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2922]: 
DBG:tm:retransmission_handler: retransmission_handler : request resending 
(t=0xb5bc5698, BYE sip:1 ... )
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2922]: DBG:tm:set_timer: 
relative timeout is 1000000
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2922]: 
DBG:tm:insert_timer_unsafe: [5]: 0xb5bc57e4 (348700000)
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2922]: 
DBG:tm:retransmission_handler: retransmission_handler : done
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: 
DBG:core:parse_msg: SIP Reply  (status):
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: 
DBG:core:parse_msg:  version: <SIP/2.0>
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: 
DBG:core:parse_msg:  status:  <200>
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: 
DBG:core:parse_msg:  reason:  <OK>
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: 
DBG:core:parse_headers: flags=2
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: 
DBG:core:parse_via_param: found param type 232, <branch> = 
<z9hG4bK0a12.d34802f2.0>; state=9
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: 
DBG:core:parse_via: next_via
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: 
DBG:core:parse_via_param: found param type 235, <rport> = <5060>; state=6
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: 
DBG:core:parse_via_param: found param type 234, <received> = <10.10.45.78>; 
state=6
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: 
DBG:core:parse_via_param: found param type 232, <branch> = 
<z9hG4bK0a0a2d4e00000023496db628368fa1040000002e>; state=16
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: 
DBG:core:parse_via: end of header reached, state=5
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: 
DBG:core:parse_headers: via found, flags=2
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: 
DBG:core:parse_headers: this is the first via
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: 
DBG:core:receive_msg: After parse_msg...
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: 
DBG:core:forward_reply: found module nat_traversal, passing reply to it
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: 
DBG:core:parse_headers: flags=4
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: 
DBG:core:forward_reply: found module tm, passing reply to it
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: DBG:tm:t_check: 
start=0xffffffff
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: 
DBG:core:parse_headers: flags=22
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: 
DBG:core:get_hdr_field: content_length=0
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: 
DBG:core:get_hdr_field: cseq <CSeq>: <1> <BYE>
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: 
DBG:tm:t_reply_matching: hash 8608 label 790660157 branch 0
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: 
DBG:tm:t_reply_matching: REF_UNSAFE: after is 1
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: 
DBG:tm:t_reply_matching: reply matched (T=0xb5bc5698)!
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: 
DBG:tm:run_trans_callbacks: trans=0xb5bc5698, callback type 2, id 3 entered
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: 
DBG:core:parse_headers: flags=8
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: 
DBG:core:parse_to_param: tag=356629413371487987
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: DBG:core:parse_to: 
end of header reached, state=29
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: DBG:core:parse_to: 
display={"Sjphone laptop_User"}, ruri={sip:[email protected]}
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: 
DBG:core:get_hdr_field: <To> [66]; uri=[sip:[email protected]]
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: 
DBG:core:get_hdr_field: to body ["Sjphone laptop_User"<sip:[email protected]>]
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: 
DBG:tm:run_trans_callbacks: trans=0xb5bc5698, callback type 2, id 1 entered
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: 
DBG:core:parse_to_param: tag=35661671621893720533
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: DBG:core:parse_to: 
end of header reached, state=29
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: DBG:core:parse_to: 
display={"SJphone User"}, ruri={sip:[email protected]}
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: 
DBG:core:parse_headers: flags=40
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: 
DBG:siptrace:trace_onreply_in: storing info...
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: DBG:tm:t_check: 
end=0xb5bc5698
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: 
DBG:tm:reply_received: org. status uas=200, uac[0]=200 local=0 is_invite=0)
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: 
DBG:tm:t_should_relay_response: T_code=200, new_code=200
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: 
DBG:tm:relay_reply: branch=0, save=0, relay=-1
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: DBG:tm:t_unref: 
UNREF_UNSAFE: after is 0
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: 
DBG:core:destroy_avp_list: destroying list (nil)
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: 
DBG:core:receive_msg: cleaning up
Jan 14 10:04:25 opensips-lab /usr/local/sbin/opensips[2922]: 
DBG:tm:utimer_routine: timer routine:5,tl=0xb5bc57e4 next=(nil), 
timeout=348700000
Jan 14 10:04:26 opensips-lab /usr/local/sbin/opensips[2919]: 
DBG:core:udp_rcv_loop: probing packet received from 10.10.45.78 50451
Jan 14 10:04:26 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:udp_rcv_loop: probing packet received from 10.10.45.102 50195
Jan 14 10:04:29 opensips-lab /usr/local/sbin/opensips[2922]: 
DBG:tm:timer_routine: timer routine:2,tl=0xb5bc56e0 next=(nil), timeout=352
Jan 14 10:04:29 opensips-lab /usr/local/sbin/opensips[2922]: 
DBG:tm:wait_handler: removing 0xb5bc5698 from table
Jan 14 10:04:29 opensips-lab /usr/local/sbin/opensips[2922]: 
DBG:tm:delete_cell: delete transaction 0xb5bc5698
Jan 14 10:04:29 opensips-lab /usr/local/sbin/opensips[2922]: 
DBG:tm:wait_handler: done
Jan 14 10:04:31 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:udp_rcv_loop: probing packet received from 10.10.45.102 50195
Jan 14 10:04:32 opensips-lab /usr/local/sbin/opensips[2918]: 
DBG:core:udp_rcv_loop: probing packet received from 10.10.45.78 50451
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_msg: SIP Reply  (status):
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_msg:  version: <SIP/2.0>
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_msg:  status:  <200>
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_msg:  reason:  <Ok>
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_headers: flags=2
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_via_param: found param type 232, <branch> = <0>; state=16
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_via: end of header reached, state=5
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_headers: via found, flags=2
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_headers: this is the first via
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:receive_msg: After parse_msg...
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:forward_reply: found module nat_traversal, passing reply to it
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_headers: flags=4
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_to_param: tag=1660725641
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2921]: DBG:core:parse_to: 
end of header reached, state=29
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2921]: DBG:core:parse_to: 
display={}, ruri={sip:10.10.45.78:5061}
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:get_hdr_field: <To> [39]; uri=[sip:10.10.45.78:5061]
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:get_hdr_field: to body [<sip:10.10.45.78:5061>]
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:get_hdr_field: cseq <CSeq>: <1> <NOTIFY>
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:get_hdr_field: content_length=0
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:get_hdr_field: found end of header
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:destroy_avp_list: destroying list (nil)
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:receive_msg: cleaning up
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:parse_msg: SIP Request:
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:parse_msg:  method:  <OPTIONS>
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:parse_msg:  uri:     <sip:10.10.45.158:5060>
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:parse_msg:  version: <SIP/2.0>
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:parse_headers: flags=2
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:parse_via_param: found param type 235, <rport> = <n/a>; state=6
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:parse_via_param: found param type 232, <branch> = 
<z9hG4bK0a0a2d6600000010496db6b965e2d07b00000036>; state=16
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:parse_via: end of header reached, state=5
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:parse_headers: via found, flags=2
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:parse_headers: this is the first via
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:receive_msg: After parse_msg...
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:receive_msg: preparing to run routing scripts...
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:parse_headers: flags=10
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:get_hdr_field: content_length=0
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:get_hdr_field: cseq <CSeq>: <7> <OPTIONS>
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:parse_to_param: tag=35663230771452839795
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: DBG:core:parse_to: 
end of header reached, state=29
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: DBG:core:parse_to: 
display={}, ruri={sip:[email protected]}
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:parse_headers: flags=8
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: DBG:core:parse_to: 
end of header reached, state=10
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: DBG:core:parse_to: 
display={}, ruri={sip:10.10.45.158:5060}
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:get_hdr_field: <To> [25]; uri=[sip:10.10.45.158:5060]
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:get_hdr_field: to body [<sip:10.10.45.158:5060>^M ]
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: New request - 
M=OPTIONS RURI=sip:10.10.45.158:5060 F=sip:[email protected] 
T=sip:10.10.45.158:5060 IP=10.10.45.102 
[email protected]
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:maxfwd:is_maxfwd_present: value = 70
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: DBG:uri:has_totag: 
no totag
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:parse_headers: flags=78
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:tm:t_lookup_request: start searching: hash=15634, isACK=0
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:tm:matching_3261: RFC3261 transaction matching failed
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:tm:t_lookup_request: no transaction found
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: Recording Route 
info
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: risposta per 
l'OPTIONS
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:parse_headers: flags=ffffffffffffffff
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:get_hdr_field: found end of header
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:check_via_address: params 10.10.45.102, 10.10.45.102, 0
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:sl:run_sl_callbacks: callback id 2 entered
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:sl:run_sl_callbacks: callback id 0 entered
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:siptrace:trace_sl_onreply_out: trace off...
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:destroy_avp_list: destroying list (nil)
Jan 14 10:04:33 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:receive_msg: cleaning up
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: 
DBG:core:parse_msg: SIP Request:
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: 
DBG:core:parse_msg:  method:  <OPTIONS>
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: 
DBG:core:parse_msg:  uri:     <sip:10.10.45.158:5060>
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: 
DBG:core:parse_msg:  version: <SIP/2.0>
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: 
DBG:core:parse_headers: flags=2
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: 
DBG:core:parse_via_param: found param type 235, <rport> = <n/a>; state=6
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: 
DBG:core:parse_via_param: found param type 232, <branch> = 
<z9hG4bK0a0a2d4e00000010496db63b54ea9bda00000030>; state=16
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: 
DBG:core:parse_via: end of header reached, state=5
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: 
DBG:core:parse_headers: via found, flags=2
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: 
DBG:core:parse_headers: this is the first via
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: 
DBG:core:receive_msg: After parse_msg...
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: 
DBG:core:receive_msg: preparing to run routing scripts...
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: 
DBG:core:parse_headers: flags=10
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: 
DBG:core:get_hdr_field: content_length=0
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: 
DBG:core:get_hdr_field: cseq <CSeq>: <11> <OPTIONS>
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: 
DBG:core:parse_to_param: tag=35661969111459640866
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: DBG:core:parse_to: 
end of header reached, state=29
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: DBG:core:parse_to: 
display={}, ruri={sip:[email protected]}
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: 
DBG:core:parse_headers: flags=8
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: DBG:core:parse_to: 
end of header reached, state=10
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: DBG:core:parse_to: 
display={}, ruri={sip:10.10.45.158:5060}
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: 
DBG:core:get_hdr_field: <To> [25]; uri=[sip:10.10.45.158:5060]
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: 
DBG:core:get_hdr_field: to body [<sip:10.10.45.158:5060>^M ]
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: New request - 
M=OPTIONS RURI=sip:10.10.45.158:5060 F=sip:[email protected] 
T=sip:10.10.45.158:5060 IP=10.10.45.78 
[email protected]
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: 
DBG:maxfwd:is_maxfwd_present: value = 70
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: DBG:uri:has_totag: 
no totag
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: 
DBG:core:parse_headers: flags=78
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: 
DBG:tm:t_lookup_request: start searching: hash=51335, isACK=0
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: 
DBG:tm:matching_3261: RFC3261 transaction matching failed
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: 
DBG:tm:t_lookup_request: no transaction found
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: Recording Route 
info
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: risposta per 
l'OPTIONS
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: 
DBG:core:parse_headers: flags=ffffffffffffffff
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: 
DBG:core:get_hdr_field: found end of header
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: 
DBG:core:check_via_address: params 10.10.45.78, 10.10.45.78, 0
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: 
DBG:sl:run_sl_callbacks: callback id 2 entered
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: 
DBG:sl:run_sl_callbacks: callback id 0 entered
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: 
DBG:siptrace:trace_sl_onreply_out: trace off...
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: 
DBG:core:destroy_avp_list: destroying list (nil)
Jan 14 10:04:34 opensips-lab /usr/local/sbin/opensips[2919]: 
DBG:core:receive_msg: cleaning up
Jan 14 10:04:37 opensips-lab /usr/local/sbin/opensips[2922]: 
DBG:usrloc:wb_timer: Binding '[email protected]','sip:10.10.45.102:5060' has 
expired
Jan 14 10:04:38 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:udp_rcv_loop: probing packet received from 10.10.45.102 50195
Jan 14 10:04:39 opensips-lab /usr/local/sbin/opensips[2918]: 
DBG:core:udp_rcv_loop: probing packet received from 10.10.45.78 50451
Jan 14 10:04:39 opensips-lab kernel: device eth1 left promiscuous mode
Jan 14 10:04:39 opensips-lab kernel: audit(1231923879.568:11): dev=eth1 prom=0 
old_prom=256 auid=4294967295
Jan 14 10:04:41 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_msg: SIP Reply  (status):
Jan 14 10:04:41 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_msg:  version: <SIP/2.0>
Jan 14 10:04:41 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_msg:  status:  <481>
Jan 14 10:04:41 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_msg:  reason:  <Subscription does not exist>
Jan 14 10:04:41 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_headers: flags=2
Jan 14 10:04:41 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_via_param: found param type 232, <branch> = <0>; state=16
Jan 14 10:04:41 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_via: end of header reached, state=5
Jan 14 10:04:41 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_headers: via found, flags=2
Jan 14 10:04:41 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_headers: this is the first via
Jan 14 10:04:41 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:receive_msg: After parse_msg...
Jan 14 10:04:41 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:forward_reply: found module nat_traversal, passing reply to it
Jan 14 10:04:41 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:parse_headers: flags=4
Jan 14 10:04:41 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:get_hdr_field: content_length=0
Jan 14 10:04:41 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:get_hdr_field: cseq <CSeq>: <1> <NOTIFY>
Jan 14 10:04:41 opensips-lab /usr/local/sbin/opensips[2921]: DBG:core:parse_to: 
end of header reached, state=10
Jan 14 10:04:41 opensips-lab /usr/local/sbin/opensips[2921]: DBG:core:parse_to: 
display={"SJphone User"}, ruri={sip:10.10.45.78:5060}
Jan 14 10:04:41 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:get_hdr_field: <To> [38]; uri=[sip:10.10.45.78:5060]
Jan 14 10:04:41 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:get_hdr_field: to body ["SJphone User"<sip:10.10.45.78:5060>^M ]
Jan 14 10:04:41 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:get_hdr_field: found end of header
Jan 14 10:04:41 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:destroy_avp_list: destroying list (nil)
Jan 14 10:04:41 opensips-lab /usr/local/sbin/opensips[2921]: 
DBG:core:receive_msg: cleaning up
Jan 14 10:04:44 opensips-lab /usr/local/sbin/opensips[2920]: 
DBG:core:udp_rcv_loop: probing packet received from 10.10.45.102 50195
Jan 14 10:04:45 opensips-lab /usr/local/sbin/opensips[2916]: 
DBG:core:handle_sigs: SIGTERM received, program terminates



----------------------------------------------------------------------------
Vuoi essere presente online? 
Vuoi dare voce alla tua attivita`? 
Acquista un dominio su domini.interfree.it.
A partire da 18,59 euro
----------------------------------------------------------------------------


_______________________________________________
Users mailing list
[email protected]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users

Reply via email to