[OpenSIPS-Users] BYE - 404 Not Here AND CRITICAL:dialog:log_next_state_dlg: bogus event 7 in state 2

Bogdan-Andrei Iancu bogdan at voice-system.ro
Wed Apr 21 10:02:54 CEST 2010 

Hi Alexandr,

First of all, the message in logs says - invalid BYE received while the 
call still in early state (call not established yet). That BYE is bogus 
- why does the caller sends a BYE after sending a CANCEL ?!?! makes no 
sense.

Second part, with the looping, is not related to the log you get. The 
BYE loops because is completely broken : all the routing info (RURI and 
Route hdrs) points to proxy only (the 2 interfaces of the proxy) without 
any reference to the callee IP....so opensips is keep sending to itself....

Regards,
Bogdan

Alexandr Dranchuk wrote:
>
> Hi!
>
> I got this and now ask if someone can tell me if it's normal or I 
> should do something with...
>
>
>
> I debuging OpenSIPS 1.6.2 on multihomed PC with mhomed=1
>
> where OpenSIPS has public IP 8.8.2.2 and on second interface private 
> 192.168.1.200
>
> calls terminated to gateway 192.168.1.203
>
>
>
> So issue happens on call not being connected, but right after CANCEL 
> when I get BYE method from caller!
>
>
>
> I got this error at every similar BYE
>
> Apr 21 01:18:06 ser /usr/sbin/opensips[590]: 
> CRITICAL:dialog:log_next_state_dlg: bogus event 7 in state 2 for dlg 
> 0xb3b8e304 [1541:1721026758] with clid '320623852 at 1.1.1.1' and tags 
> '1779091552' 'b151f93a-724884'
>
>
>
> and SIP TRACE shows strange loop of BYE message from 1 interface to 
> another at the same host
>
> causing this error:
>
> #
> U 2010/04/21 01:17:29.568172 1.1.1.1:5060 -> 8.8.2.2:5060
> INVITE sip:0583 at 8.8.2.2 SIP/2.0.
> Max-Forwards: 20.
> Via: SIP/2.0/UDP 1.1.1.1:5060;rport;branch=z9hG4bK228107990.
> From: <sip:8795 at 1.1.1.1>;tag=1779091552.
> To: <sip:0583 at 8.8.2.2>.
> Call-ID: 320623852 at 1.1.1.1.
> CSeq: 1220310 INVITE.
> User-Agent: MediaCore/0.9.
> Contact: <sip:8795 at 1.1.1.1:5060>.
> Allow: ACK, INVITE, BYE, CANCEL, REGISTER, REFER, OPTIONS, INFO.
> Content-Type: application/sdp.
> Content-Length: 206.
> .
> v=0.
> o=mc 1271790746 1271790746 IN IP4 1.1.1.1.
> s=SIP Call.
> c=IN IP4 1.1.1.1.
> t=0 0.
> m=audio 18594 RTP/AVP 18 101.
> a=rtpmap:18 G729/8000.
> a=fmtp:18 annexb=no.
> a=rtpmap:101 telephone-event/8000.
>
> #
> U 2010/04/21 01:17:29.585860 8.8.2.2:5060 -> 1.1.1.1:5060
> SIP/2.0 100 Giving a try.
> Via: SIP/2.0/UDP 1.1.1.1:5060;rport=5060;branch=z9hG4bK228107990.
> From: <sip:8795 at 1.1.1.1>;tag=1779091552.
> To: <sip:0583 at 8.8.2.2>.
> Call-ID: 320623852 at 1.1.1.1.
> CSeq: 1220310 INVITE.
> Server: Proxy.
> Content-Length: 0.
> .
>
> #
> U 2010/04/21 01:17:29.585970 192.168.1.200:5060 -> 192.168.1.203:5060
> INVITE sip:560583 at 192.168.1.203:5060 SIP/2.0.
> Record-Route: 
> <sip:192.168.1.200;r2=on;lr=on;ftag=1779091552;did=506.6c8c4966;vsf=AAAAAAAFDQcACQIKBQx1cQgLHR8HCBofCB4FHgE->.
> Record-Route: 
> <sip:8.8.2.2;r2=on;lr=on;ftag=1779091552;did=506.6c8c4966;vsf=AAAAAAAFDQcACQIKBQx1cQgLHR8HCBofCB4FHgE->.
> Max-Forwards: 19.
> Via: SIP/2.0/UDP 192.168.1.200;branch=z9hG4bK8852.a7f98af4.0.
> Via: SIP/2.0/UDP 
> 1.1.1.1:5060;received=1.1.1.1;rport=5060;branch=z9hG4bK228107990.
> From: "2225" <sip:2225 at 192.168.1.200>;tag=1779091552.
> To: <sip:0583 at 8.8.2.2>.
> Call-ID: 320623852 at 1.1.1.1.
> CSeq: 1220310 INVITE.
> User-Agent: MediaCore/0.9.
> Contact: <sip:8795 at 1.1.1.1:5060>.
> Allow: ACK, INVITE, BYE, CANCEL, REGISTER, REFER, OPTIONS, INFO.
> Content-Type: application/sdp.
> Content-Length: 206.
> .
> v=0.
> o=mc 1271790746 1271790746 IN IP4 1.1.1.1.
> s=SIP Call.
> c=IN IP4 8.8.2.2.
> t=0 0.
> m=audio 51438 RTP/AVP 18 101.
> a=rtpmap:18 G729/8000.
> a=fmtp:18 annexb=no.
> a=rtpmap:101 telephone-event/8000.
>
> #
> U 2010/04/21 01:17:29.634981 192.168.1.203:5060 -> 192.168.1.200:5060
> SIP/2.0 100 Trying.
> Via: SIP/2.0/UDP 192.168.1.200;branch=z9hG4bK8852.a7f98af4.0.
> Via: SIP/2.0/UDP 
> 1.1.1.1:5060;rport=5060;received=1.1.1.1;branch=z9hG4bK228107990.
> From: "2225" <sip:2225 at 192.168.1.200>;tag=1779091552.
> To: <sip:0583 at 8.8.2.2>.
> Call-ID: 320623852 at 1.1.1.1.
> CSeq: 1220310 INVITE.
> Content-Type: application/sdp.
> Content-Length: 0.
> .
>
> #
> U 2010/04/21 01:17:30.618689 192.168.1.203:5060 -> 192.168.1.200:5060
> SIP/2.0 180 Ringing.
> Via: SIP/2.0/UDP 192.168.1.200;branch=z9hG4bK8852.a7f98af4.0.
> Via: SIP/2.0/UDP 
> 1.1.1.1:5060;rport=5060;received=1.1.1.1;branch=z9hG4bK228107990.
> From: "2225" <sip:2225 at 192.168.1.200>;tag=1779091552.
> To: <sip:0583 at 8.8.2.2>;tag=b151f93a-724884.
> Call-ID: 320623852 at 1.1.1.1.
> CSeq: 1220310 INVITE.
> Contact: <sip:mygw at 192.168.1.203:5060>.
> Record-Route: 
> <sip:192.168.1.200;r2=on;lr=on;ftag=1779091552;did=506.6c8c4966;vsf=AAAAAAAFDQcACQIKBQx1cQgLHR8HCBofCB4FHgE->,<sip:8.8.2.2;r2=on;lr=on;ftag=1779091552;did=506.6c8c4966;vsf=AAAAAAAFDQcACQIKBQx1cQgLHR8HCBofCB4FHgE->.
> User-Agent: 048 12-35-3923109.
> Content-Length: 0.
> .
>
> #
> U 2010/04/21 01:17:30.619521 8.8.2.2:5060 -> 1.1.1.1:5060
> SIP/2.0 180 Ringing.
> Via: SIP/2.0/UDP 
> 1.1.1.1:5060;rport=5060;received=1.1.1.1;branch=z9hG4bK228107990.
> From: <sip:8795 at 1.1.1.1>;tag=1779091552.
> To: <sip:0583 at 8.8.2.2>;tag=b151f93a-724884.
> Call-ID: 320623852 at 1.1.1.1.
> CSeq: 1220310 INVITE.
> Contact: <sip:mygw at 192.168.1.203:5060>.
> Record-Route: 
> <sip:192.168.1.200;r2=on;lr=on;ftag=1779091552;did=506.6c8c4966;vsf=AAAAAAAFDQcACQIKBQx1cQgLHR8HCBofCB4FHgE->,<sip:8.8.2.2;r2=on;lr=on;ftag=1779091552;did=506.6c8c4966;vsf=AAAAAAAFDQcACQIKBQx1cQgLHR8HCBofCB4FHgE->.
> User-Agent: 048 12-35-3923109.
> Content-Length: 0.
> .
>
> #
> U 2010/04/21 01:18:06.341867 1.1.1.1:5060 -> 8.8.2.2:5060
> CANCEL sip:0583 at 8.8.2.2 SIP/2.0.
> Via: SIP/2.0/UDP 1.1.1.1:5060;rport;branch=z9hG4bK228107990.
> From: <sip:8795 at 1.1.1.1>;tag=1779091552.
> To: <sip:0583 at 8.8.2.2>.
> Call-ID: 320623852 at 1.1.1.1.
> CSeq: 1220310 CANCEL.
> User-Agent: MediaCore/0.9.
> Max-Forwards: 70.
> Allow: ACK, INVITE, BYE, CANCEL, REGISTER, REFER, OPTIONS, INFO.
> Content-Length: 0.
> .
>
> #
> U 2010/04/21 01:18:06.342096 8.8.2.2:5060 -> 1.1.1.1:5060
> SIP/2.0 200 canceling.
> Via: SIP/2.0/UDP 1.1.1.1:5060;rport=5060;branch=z9hG4bK228107990.
> From: <sip:8795 at 1.1.1.1>;tag=1779091552.
> To: <sip:0583 at 8.8.2.2>;tag=155c340f586c28d0300cf5a6ccf90d99-7e51.
> Call-ID: 320623852 at 1.1.1.1.
> CSeq: 1220310 CANCEL.
> Server: Proxy.
> Content-Length: 0.
> .
>
> #
> U 2010/04/21 01:18:06.342096 8.8.2.2:5060 -> 1.1.1.1:5060
> SIP/2.0 200 canceling.
> Via: SIP/2.0/UDP 1.1.1.1:5060;rport=5060;branch=z9hG4bK228107990.
> From: <sip:8795 at 1.1.1.1>;tag=1779091552.
> To: <sip:0583 at 8.8.2.2>;tag=155c340f586c28d0300cf5a6ccf90d99-7e51.
> Call-ID: 320623852 at 1.1.1.1.
> CSeq: 1220310 CANCEL.
> Server: Proxy.
> Content-Length: 0.
> .
>
> #
> U 2010/04/21 01:18:06.342555 1.1.1.1:5060 -> 8.8.2.2:5060
> BYE sip:0583 at 8.8.2.2 SIP/2.0.
> Route: 
> <sip:8.8.2.2;r2=on;lr=on;ftag=1779091552;did=506.6c8c4966;vsf=AAAAAAAFDQcACQIKBQx1cQgLHR8HCBofCB4FHgE->.
> Route: 
> <sip:192.168.1.200;r2=on;lr=on;ftag=1779091552;did=506.6c8c4966;vsf=AAAAAAAFDQcACQIKBQx1cQgLHR8HCBofCB4FHgE->.
> Call-ID: 320623852 at 1.1.1.1.
> From: <sip:8795 at 1.1.1.1>;tag=1779091552.
> To: <sip:0583 at 8.8.2.2>;tag=b151f93a-724884.
> Reason: Q850;cause=16.
> Via: SIP/2.0/UDP 1.1.1.1:5060;rport;branch=z9hG4bK52996011.
> CSeq: 1220400 BYE.
> User-Agent: MediaCore/0.9.
> Max-Forwards: 70.
> Allow: ACK, INVITE, BYE, CANCEL, REGISTER, REFER, OPTIONS, INFO.
> Content-Length: 0.
> .
>
> [[[[[[[[[[[[[[[HERE IS MESSAGE THAT COMES FROM OpenSIPS TO HIMSELF BUT 
> AT ANOTHER interface!]]]]]]]]]]]]]]]]]]]]]
>
> #
> U 2010/04/21 01:18:06.342809 8.8.2.2:5060 -> 192.168.1.200:5060
> BYE 
> sip:192.168.1.200;r2=on;lr=on;ftag=1779091552;did=506.6c8c4966;vsf=AAAAAAAFDQcACQIKBQx1cQgLHR8HCBofCB4FHgE- 
> SIP/2.0.
> Call-ID: 320623852 at 1.1.1.1.
> From: <sip:8795 at 1.1.1.1>;tag=1779091552.
> To: <sip:0583 at 8.8.2.2>;tag=b151f93a-724884.
> Reason: Q850;cause=16.
> Via: SIP/2.0/UDP 8.8.2.2;branch=z9hG4bKf348.cc3dffa2.0.
> Via: SIP/2.0/UDP 
> 1.1.1.1:5060;received=1.1.1.1;rport=5060;branch=z9hG4bK52996011.
> CSeq: 1220400 BYE.
> User-Agent: MediaCore/0.9.
> Max-Forwards: 69.
> Allow: ACK, INVITE, BYE, CANCEL, REGISTER, REFER, OPTIONS, INFO.
> Content-Length: 0.
> .
>
> #
> U 2010/04/21 01:18:06.342861 192.168.1.200:5060 -> 192.168.1.203:5060
> CANCEL sip:560583 at 192.168.1.203:5060 SIP/2.0.
> Via: SIP/2.0/UDP 192.168.1.200;branch=z9hG4bK8852.a7f98af4.0.
> From: "2225" <sip:2225 at 192.168.1.200>;tag=1779091552.
> Call-ID: 320623852 at 1.1.1.1.
> To: <sip:0583 at 8.8.2.2>.
> CSeq: 1220310 CANCEL.
> Max-Forwards: 70.
> User-Agent: D.
> Content-Length: 0.
> .
>
> [[[[[[[[[[[[[[[HERE IS REPLY MESSAGE THAT COMES FROM OpenSIPS TO 
> HIMSELF BUT AT ANOTHER interface!]]]]]]]]]]]]]]]]]]]]]
> [[[[[[[[[[[[[[[this make CRITICAL:dialog:log_next_state_dlg: bogus 
> event 7 in state 2]]]]]]]]]]]]]]]]]]]]]
>
> #
> U 2010/04/21 01:18:06.342912 192.168.1.200:5060 -> 8.8.2.2:5060
> SIP/2.0 404 Not here.
> Call-ID: 320623852 at 1.1.1.1.
> From: <sip:8795 at 1.1.1.1>;tag=1779091552.
> To: <sip:0583 at 8.8.2.2>;tag=b151f93a-724884.
> Via: SIP/2.0/UDP 8.8.2.2;branch=z9hG4bKf348.cc3dffa2.0.
> Via: SIP/2.0/UDP 
> 1.1.1.1:5060;received=1.1.1.1;rport=5060;branch=z9hG4bK52996011.
> CSeq: 1220400 BYE.
> Server: Proxy.
> Content-Length: 0.
> .
>
> #
> U 2010/04/21 01:18:06.343074 8.8.2.2:5060 -> 1.1.1.1:5060
> SIP/2.0 404 Not here.
> Call-ID: 320623852 at 1.1.1.1.
> From: <sip:8795 at 1.1.1.1>;tag=1779091552.
> To: <sip:0583 at 8.8.2.2>;tag=b151f93a-724884.
> Via: SIP/2.0/UDP 
> 1.1.1.1:5060;received=1.1.1.1;rport=5060;branch=z9hG4bK52996011.
> CSeq: 1220400 BYE.
> Server: Proxy.
> Content-Length: 0.
> .
>
> #
> U 2010/04/21 01:18:06.416211 192.168.1.203:5060 -> 192.168.1.200:5060
> SIP/2.0 487 Request Terminated.
> Via: SIP/2.0/UDP 192.168.1.200;branch=z9hG4bK8852.a7f98af4.0.
> Via: SIP/2.0/UDP 
> 1.1.1.1:5060;rport=5060;received=1.1.1.1;branch=z9hG4bK228107990.
> From: "2225" <sip:2225 at 192.168.1.200>;tag=1779091552.
> To: <sip:0583 at 8.8.2.2>;tag=b151f93a-724884.
> Call-ID: 320623852 at 1.1.1.1.
> CSeq: 1220310 INVITE.
> Record-Route: 
> <sip:192.168.1.200;r2=on;lr=on;ftag=1779091552;did=506.6c8c4966;vsf=AAAAAAAFDQcACQIKBQx1cQgLHR8HCBofCB4FHgE->,<sip:8.8.2.2;r2=on;lr=on;ftag=1779091552;did=506.6c8c4966;vsf=AAAAAAAFDQcACQIKBQx1cQgLHR8HCBofCB4FHgE->.
> User-Agent: 048 12-35-3923109.
> Content-Length: 0.
> .
>
> #
> U 2010/04/21 01:18:06.416896 192.168.1.200:5060 -> 192.168.1.203:5060
> ACK sip:560583 at 192.168.1.203:5060 SIP/2.0.
> Via: SIP/2.0/UDP 192.168.1.200;branch=z9hG4bK8852.a7f98af4.0.
> From: "2225" <sip:2225 at 192.168.1.200>;tag=1779091552.
> Call-ID: 320623852 at 1.1.1.1.
> To: <sip:0583 at 8.8.2.2>;tag=b151f93a-724884.
> CSeq: 1220310 ACK.
> Max-Forwards: 70.
> User-Agent: D.
> Content-Length: 0.
> .
>
> #
> U 2010/04/21 01:18:06.422826 192.168.1.203:5060 -> 192.168.1.200:5060
> SIP/2.0 200 OK.
> Via: SIP/2.0/UDP 192.168.1.200;branch=z9hG4bK8852.a7f98af4.0.
> From: "2225" <sip:2225 at 192.168.1.200>;tag=1779091552.
> To: <sip:0583 at 8.8.2.2>;tag=b151f93a-724884.
> Call-ID: 320623852 at 1.1.1.1.
> CSeq: 1220310 CANCEL.
> User-Agent: 048 12-35-3923109.
> Content-Length: 0.
> .
>
> #
> U 2010/04/21 01:18:06.455191 8.8.2.2:5060 -> 1.1.1.1:5060
> SIP/2.0 487 Request Terminated.
> Via: SIP/2.0/UDP 
> 1.1.1.1:5060;rport=5060;received=1.1.1.1;branch=z9hG4bK228107990.
> From: <sip:8795 at 1.1.1.1>;tag=1779091552.
> To: <sip:0583 at 8.8.2.2>;tag=b151f93a-724884.
> Call-ID: 320623852 at 1.1.1.1.
> CSeq: 1220310 INVITE.
> Record-Route: 
> <sip:192.168.1.200;r2=on;lr=on;ftag=1779091552;did=506.6c8c4966;vsf=AAAAAAAFDQcACQIKBQx1cQgLHR8HCBofCB4FHgE->,<sip:8.8.2.2;r2=on;lr=on;ftag=1779091552;did=506.6c8c4966;vsf=AAAAAAAFDQcACQIKBQx1cQgLHR8HCBofCB4FHgE->.
> User-Agent: 048 12-35-3923109.
> Content-Length: 0.
> .
>
> #
> U 2010/04/21 01:18:06.573706 1.1.1.1:5060 -> 8.8.2.2:5060
> ACK sip:0583 at 8.8.2.2 SIP/2.0.
> Via: SIP/2.0/UDP 1.1.1.1:5060;rport;branch=z9hG4bK228107990.
> From: <sip:8795 at 1.1.1.1>;tag=1779091552.
> To: <sip:0583 at 8.8.2.2>;tag=b151f93a-724884.
> Call-ID: 320623852 at 1.1.1.1.
> CSeq: 1220310 ACK.
> Max-Forwards: 20.
> Contact: <sip:8795 at 1.1.1.1:5060>.
> User-Agent: MediaCore/0.9.
> Content-Length: 0.
> .
>
> ------------------------------------------------------------------------
>
> _______________________________________________
> Users mailing list
> Users at lists.opensips.org
> http://lists.opensips.org/cgi-bin/mailman/listinfo/users
>   


-- 
Bogdan-Andrei Iancu
www.voice-system.ro

More information about the Users mailing list