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

Wed Apr 21 15:12:33 CEST 2010

Got it. My goof. after rereading RFC I found it.
Looks like caller's device support old RFC2543 where it's allowed.
Thus I can nothing to do with coming bogus BYE requests.

One more question I got, is sometimes I got same BYE after CANCEL without
TO_TAG

so, the question is what's the best solution? Drop the BYE without TO TAG
or continue
forward it to PSTN GW? 

Thank You very much for your previous answers.

On Wed, 21 Apr 2010 15:25:41 +0300, Bogdan-Andrei Iancu
<bogdan at voice-system.ro> wrote:
> well, first of all, without a 200 OK, it is rather impossible to built a

> valid BYE. Because the BYE must contain the remove address (of the other

> party - callee here) and the Route set (all the RR headers) - all this 
> info is collected from 200 OK.
> 
> So, the RURI in BYE must be the contact in 200 OK INVITE . The INVITE 
> and the BYE requests are differently built (first is an initial request,

> second a sequential request)
> 
> Regards,
> Bogdan
> 
> Alexandr Dranchuk wrote:
>> Hi Bogdan!
>>
>> Sorry for bothering You, but... it's not quite clear to me why the BYE
>> broken?
>> for caller it's unknown callee IP, and for INVITE I call
>> forward(192.168.1.203) function
>> to reach callee. So should I call forward(192.168.1.203) for the BYE
>> also?
>>
>> about invalid BYE, I completely agree about, but have no idea why I get
>> BYE after
>> CANCEL... since I haev no access to caller device, can't check it. 
>>
>> Thank You
>>
>> On Wed, 21 Apr 2010 11:02:54 +0300, Bogdan-Andrei Iancu
>> <bogdan at voice-system.ro> wrote:
>>   
>>> 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
>>>>
>>>>       
>>
>>

-- 
ТОО "ДАВИОН"
Директор: Александр Дранчук