[OpenSIPS-Users] Strange retrasmission of bye messages
mmarzuola at interfree.it
mmarzuola at interfree.it
Wed Jan 14 11:12:02 CET 2009
>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:1000 at 10.10.45.102: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:1002 at mysip.com}
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:1000 at mysip.com}
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: DBG:core:get_hdr_field: <To> [45]; uri=[sip:1000 at mysip.com]
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: DBG:core:get_hdr_field: to body [<sip:1000 at mysip.com>]
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2921]: New request - M=BYE RURI=sip:1000 at 10.10.45.102:1024 F=sip:1002 at mysip.com T=sip:1000 at mysip.com IP=10.10.45.78 ID=80746482-1DD2-11B2-967C-BF03D96637AB at 10.10.45.102
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 80746482-1DD2-11B2-967C-BF03D96637AB at 10.10.45.102: 1000 at mysip.com (356629413371487987) --> 1002 at mysip.com
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': '80746482-1DD2-11B2-967C-BF03D96637AB at 10.10.45.102', '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': '1002 at mysip.com', 'from_uri': '1000 at mysip.com', '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:1000 at mysip.com}
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: DBG:core:get_hdr_field: <To> [66]; uri=[sip:1000 at mysip.com]
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2920]: DBG:core:get_hdr_field: to body ["Sjphone laptop_User"<sip:1000 at mysip.com>]
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:1002 at mysip.com}
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: 80746482-1DD2-11B2-967C-BF03D96637AB at 10.10.45.102^M CSeq: 1 BYE^M From: "SJphone User"<sip:1002 at mysip.com>;tag=35661671621893720533^M Server: SJphone/1.60.299a/L (SJ Labs)^M To: "Sjphone laptop_User"<sip:1000 at mysip.com>;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;call_id=80746482-1DD2-11B2-967C-BF03D96637AB at 10.10.45.102;code=200;reason=OK;caller_id=sip:1002 at mysip.com;callee_id=sip:1000 at mysip.com;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:1000 at mysip.com}
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: DBG:core:get_hdr_field: <To> [66]; uri=[sip:1000 at mysip.com]
Jan 14 10:04:24 opensips-lab /usr/local/sbin/opensips[2918]: DBG:core:get_hdr_field: to body ["Sjphone laptop_User"<sip:1000 at mysip.com>]
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:1002 at mysip.com}
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:1000 at mysip.com}
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:1000 at mysip.com T=sip:10.10.45.158:5060 IP=10.10.45.102 ID=4A2DE9FC-1DD2-11B2-967C-BF03D96637AB at 10.10.45.102
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:1002 at mysip.com}
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:1002 at mysip.com T=sip:10.10.45.158:5060 IP=10.10.45.78 ID=C8288944-1DD1-11B2-93F8-D1EC39B737C3 at 10.10.45.78
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 '1000 at mysip.com','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
----------------------------------------------------------------------------
More information about the Users
mailing list