Re: [Linphone-users] Problem with incoming calls when busy...

[Magnus Sandin]

Hello Simon.

This is the scenario:

1. I start linphone
2. I'm placing a call from linphone
3. I call linphone from another phone

I have included the logs from step 2 above:

| INFO1 | <eXosip.c: 339> eXosip: timer sec:0 usec:149!
| INFO1 | <jcallback.c: 321> cb_nist_kill_transaction (id=7)
| INFO1 | <eXosip.c: 339> eXosip: timer sec:0 usec:10354!
| INFO1 | <jcallback.c: 321> cb_nist_kill_transaction (id=8)
| INFO1 | <eXosip.c: 339> eXosip: timer sec:0 usec:13840!
| INFO1 | <eXosip.c: 339> eXosip: timer sec:0 usec:422!
| INFO1 | <jcallback.c: 321> cb_nist_kill_transaction (id=9)
| INFO1 | <eXosip.c: 339> eXosip: timer sec:0 usec:21008!
| INFO1 | <jcallback.c: 321> cb_nist_kill_transaction (id=10)
| INFO1 | <eXosip.c: 339> eXosip: timer sec:0 usec:10275!
| INFO1 | <jcallback.c: 321> cb_nist_kill_transaction (id=11)
| INFO1 | <eXosip.c: 332> eXosip: Reseting timer to 15s before waking up!
| INFO1 | <eXosip.c: 339> eXosip: timer sec:4 usec:2520!
| INFO1 | <eXosip.c: 339> eXosip: timer sec:0 usec:126!
| INFO1 | <jcallback.c: 189> cb_ict_kill_transaction (id=13)
| INFO1 | <eXosip.c: 332> eXosip: Reseting timer to 15s before waking up!
| INFO1 | <udp.c: 2193> Received message:
INVITE sip:address@hidden:5060 SIP/2.0
Via: SIP/2.0/UDP aa.bb.cc.dd:5060;branch=z9hG4bK4285f30d
From: "Unknown" <sip:address@hidden>;tag=as266b87dc
To: <sip:address@hidden:5060>
Contact: <sip:address@hidden>
Call-ID: address@hidden
CSeq: 102 INVITE
User-Agent: Asterisk PBX
Date: Sun, 02 Oct 2005 12:21:04 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER
Content-Type: application/sdp
Content-Length: 215

v=0
o=root 2289 2289 IN IP4 aa.bb.cc.dd
s=session
c=IN IP4 aa.bb.cc.dd
t=0 0
m=audio 14034 RTP/AVP 3 101
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -

| INFO3 | <osip_event.c: 84> MESSAGE REC.
CALLID:3bf5cecb35000d767d0e53fd6e9f0456
| INFO1 | <udp.c: 2228> This is a request
| INFO2 | <osip_transaction.c: 129> allocating transaction ressource 15
3bf5cecb35000d767d0e53fd6e9f0456
| INFO2 | <ist.c: 32> allocating IST context
| INFO1 | <eXutils.c: 416> Outgoing interface to reach aa.bb.cc.dd is
10.104.2.17.

| INFO1 | <jcallback.c: 332> cb_rcvinvite (id=15)
| INFO2 | <eXutils.c: 492> IPv4 address detected: aa.bb.cc.dd
| INFO2 | <eXutils.c: 541> DNS resolution with aa.bb.cc.dd:5060
| INFO1 | <jcallback.c: 148> Message sent:
SIP/2.0 100 Trying
Via: SIP/2.0/UDP aa.bb.cc.dd:5060;branch=z9hG4bK4285f30d
From: "Unknown" <sip:address@hidden>;tag=as266b87dc
To: <sip:address@hidden:5060>
Call-ID: address@hidden
CSeq: 102 INVITE
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, MESSAGE, INFO
Content-Length: 0

 (len=16 sizeof(addr)=128 28)
| INFO1 | <jcallback.c: 1669> cb_snd1xx (id=15)
| INFO2 | <eXutils.c: 492> IPv4 address detected: aa.bb.cc.dd
| INFO2 | <eXutils.c: 541> DNS resolution with aa.bb.cc.dd:5060
| INFO1 | <jcallback.c: 148> Message sent:
SIP/2.0 101 Dialog Establishement
Via: SIP/2.0/UDP aa.bb.cc.dd:5060;branch=z9hG4bK4285f30d
From: "Unknown" <sip:address@hidden>;tag=as266b87dc
To: <sip:address@hidden:5060>;tag=1745034882
Call-ID: address@hidden
CSeq: 102 INVITE
Contact: <sip:address@hidden:5060>
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, MESSAGE, INFO
Content-Length: 0

 (len=16 sizeof(addr)=128 28)
| INFO1 | <jcallback.c: 1669> cb_snd1xx (id=15)
| INFO1 | <eXosip.c: 332> eXosip: Reseting timer to 15s before waking up!
| INFO1 | <eXosip.c: 332> eXosip: Reseting timer to 15s before waking up!
LinphoneCore-Message: CALL_NEW

| INFO2 | <eXutils.c: 492> IPv4 address detected: aa.bb.cc.dd
| INFO2 | <eXutils.c: 541> DNS resolution with aa.bb.cc.dd:5060
| INFO1 | <jcallback.c: 148> Message sent:
SIP/2.0 486 Busy Here
Via: SIP/2.0/UDP aa.bb.cc.dd:5060;branch=z9hG4bK4285f30d
From: "Unknown" <sip:address@hidden>;tag=as266b87dc
To: <sip:address@hidden:5060>;tag=1745034882
Call-ID: address@hidden
CSeq: 102 INVITE
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, MESSAGE, INFO
Content-Length: 0

 (len=16 sizeof(addr)=128 28)
| INFO1 | <jcallback.c: 1728> cb_snd4xx (id=15)
| INFO1 | <eXosip.c: 339> eXosip: timer sec:0 usec:499962!
| INFO1 | <udp.c: 2193> Received message:
ACK sip:address@hidden:5060 SIP/2.0
Via: SIP/2.0/UDP aa.bb.cc.dd:5060;branch=z9hG4bK4285f30d
From: "Unknown" <sip:address@hidden>;tag=as266b87dc
To: <sip:address@hidden:5060>;tag=1745034882
Contact: <sip:address@hidden>
Call-ID: address@hidden
CSeq: 102 ACK
User-Agent: Asterisk PBX
Content-Length: 0


| INFO3 | <osip_event.c: 84> MESSAGE REC.
CALLID:3bf5cecb35000d767d0e53fd6e9f0456
| INFO1 | <jcallback.c: 337> cb_rcvack (id=15)
| INFO1 | <eXosip.c: 339> eXosip: timer sec:4 usec:999968!
LinphoneCore-Message: CALL_CLOSED or CANCELLED

LinphoneCore-Message: Call terminated...
MediaStreamer-Message: Mediastreamer processing thread is exiting.
MediaStreamer-Message: Closing reading channel of soundcard.
MediaStreamer-Message: Closing writing channel of soundcard.
oRTP-stats-Message:
   Global statistics :
 number of rtp packet sent=1700
 number of rtp bytes sent=56100 bytes
 number of rtp packet received=1697
 number of rtp bytes received=76365 bytes
 number of incoming rtp bytes successfully delivered to the
application=76005
 number of times the application queried a packet that didn't exist=1702
 number of rtp packets received too late=0
 number of rtp packets skipped=1
 number of bad formatted rtp packets=0
 number of packet discarded because of queue overflow=0

| INFO1 | <eXosip.c: 339> eXosip: timer sec:0 usec:686!
| INFO2 | <udp.c: 2452> eXosip: eXosip_release_aborted_calls answered
with a 4xx
| INFO1 | <udp.c: 2620> Release a terminated transaction
| INFO2 | <osip_transaction.c: 286> free transaction ressource 15
3bf5cecb35000d767d0e53fd6e9f0456
| INFO2 | <ist.c: 84> free ist ressource
| INFO1 | <eXosip.c: 332> eXosip: Reseting timer to 15s before waking up!
| INFO1 | <eXosip.c: 332> eXosip: Reseting timer to 15s before waking up!
LinphoneCore-Message: CALL_RELEASED


Regards
// Magnus Sandin


*Magnus Sandin
*Cache miss - please take better aim next time




Simon Morlat wrote:

>Hello,
>
>I've reviewed the code and I don't see how possible linphone can hangup after 
>replying a 486 Busy.
>It would help me if you could send me a complete log: use linphone --verbose.
>Thanks
>
>Simon
>
>Le Lundi 26 Septembre 2005 21:58, Magnus Sandin a écrit :
>  
>
>>Hello!
>>
>>I use Linphone version 1.1.0 on Ubuntu 5.04 and I think it works really
>>good, but there seems to be one big problem.
>>
>>I have the Linphone registered to our Aterisk PBX and I can call in and
>>out, it just works great. However if I call anyone and during that call
>>anyone else calls my extension (which Linphone is registered to)
>>Linphone hangs up (Communication ended) but Asterisk is never told about
>>it!?
>>
>>The strange part is that I did a sniff on port 5060 and discovered that
>>Linphone actually tells Asterisk that the line is busy. This is also
>>indicated because the calling party is transferred to the voicemail,
>>which is the correct behaviour by Asterisk if an extension is busy.
>>
>>This is a log from SIP port 5060 when the second call comes in:
>>
>>
>>192.168.31.4 is my Linphone
>>aa.bb.cc.dd is the Asterisk PBX
>>
>>#
>>U aa.bb.cc.dd:5060 -> 192.168.31.4:5060
>>  INVITE sip:address@hidden:5060 SIP/2.0..Via: SIP/2.0/UDP
>>aa.bb.cc.dd:5060;branch=z9hG4bK26faa6bc..From: "031123456"
>>   <sip:address@hidden>;tag=as69bd634d..To:
>><sip:address@hidden:5060>..Contact: <sip:address@hidden>.
>>  .Call-ID: address@hidden: 102
>>INVITE..User-Agent: Asterisk PBX..Date: Mon, 26 Sep
>>  2005 19:47:09 GMT..Allow: INVITE, ACK, CANCEL, OPTIONS, BYE,
>>REFER..Content-Type: application/sdp..Content-Length: 215..
>>  ..v=0..o=root 3232 3232 IN IP4 aa.bb.cc.dd..s=session..c=IN IP4
>>aa.bb.cc.dd..t=0 0..m=audio 17836 RTP/AVP 3 101..a=r
>>  tpmap:3 GSM/8000..a=rtpmap:101 telephone-event/8000..a=fmtp:101
>>0-16..a=silenceSupp:off - - - -..
>>#
>>U 192.168.31.4:5060 -> aa.bb.cc.dd:5060
>>  SIP/2.0 100 Trying..Via: SIP/2.0/UDP
>>aa.bb.cc.dd:5060;branch=z9hG4bK26faa6bc..From: "031123456"
>><sip:address@hidden
>>  cc.dd>;tag=as69bd634d..To: <sip:address@hidden:5060>..Call-ID:
>>address@hidden:
>>   102 INVITE..Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE,
>>NOTIFY, MESSAGE, INFO..Content-Length: 0....
>>#
>>U 192.168.31.4:5060 -> aa.bb.cc.dd:5060
>>  SIP/2.0 101 Dialog Establishement..Via: SIP/2.0/UDP
>>aa.bb.cc.dd:5060;branch=z9hG4bK26faa6bc..From: "031123456" <sip:03
>>  address@hidden>;tag=as69bd634d..To:
>><sip:address@hidden:5060>;tag=1089067986..Call-ID:
>>0250c4a667e0657f51d43da
>>  address@hidden: 102 INVITE..Contact:
>><sip:address@hidden:5060>..Allow: INVITE, ACK, OPTIONS, CANCEL, B
>>  YE, SUBSCRIBE, NOTIFY, MESSAGE, INFO..Content-Length: 0....
>>#
>>U 192.168.31.4:5060 -> aa.bb.cc.dd:5060
>>  SIP/2.0 486 Busy Here..Via: SIP/2.0/UDP
>>aa.bb.cc.dd:5060;branch=z9hG4bK26faa6bc..From: "031123456"
>><sip:address@hidden
>>  bb.cc.dd>;tag=as69bd634d..To:
>><sip:address@hidden:5060>;tag=1089067986..Call-ID:
>>address@hidden
>>  .bb.cc.dd..CSeq: 102 INVITE..Allow: INVITE, ACK, OPTIONS, CANCEL, BYE,
>>SUBSCRIBE, NOTIFY, MESSAGE, INFO..Content-Lengt
>>  h: 0....
>>#
>>U aa.bb.cc.dd:5060 -> 192.168.31.4:5060
>>  ACK sip:address@hidden:5060 SIP/2.0..Via: SIP/2.0/UDP
>>aa.bb.cc.dd:5060;branch=z9hG4bK26faa6bc..From: "031123456" <s
>>  ip:address@hidden>;tag=as69bd634d..To:
>><sip:address@hidden:5060>;tag=1089067986..Contact: <sip:address@hidden
>>  bb.cc.dd>..Call-ID:
>>address@hidden: 102 ACK..User-Agent:
>>Asterisk PBX..Content-L
>>  ength: 0....
>>
>>
>>Any ideas why this happens?
>>
>>Regards
>>// Magnus Sandin
>>    
>>