Solved: PAP2T does not recognize busy lines

sammy_roplan · ‎03-17-2011

Hello. I was wondering if someone here might be able to shed some light on a problem I have been experiencing on my PAP2T. This unit has been working without any problems except that whenever you dial a number that is "busy" the unit will timeout with a reorder tone. I am unclear if this is specifically a provider issue or a hardware problem. Can anyone shed some light on this?

I have so far been running the latest firmware 5.1.6(LS), and downgraded to 5.1.3(LS), with no change in results. My busy tone is set to: "480@-19,620@-19;10(.5/.5/1+2)". Whenever I dial a busy number syslog reported "CC:Failed w/ Calling" when I called this "busy" number. My voip providers log states that the call placed was "BUSY". On the handset, a reorder tone was produced after dialling this number. Would this be the correct message for this call state?

The syslog messages:

Mar 16 14:55:14 192.168.0.130 Mar 16 10:55:15 0023697DF435 CC:Clean Up
Mar 16 14:55:14 192.168.0.130 Mar 16 10:55:15 0023697DF435 --- OBJ POOL STAT ---
Mar 16 14:55:14 192.168.0.130 Mar 16 10:55:15 0023697DF435 OP:RTPRXB = 96 ( 96 192)
Mar 16 14:55:14 192.168.0.130 Mar 16 10:55:15 0023697DF435 OP:RTPREB = 40 ( 40   48)
Mar 16 14:55:14 192.168.0.130 Mar 16 10:55:15 0023697DF435 OP:RTPTXB = 64 ( 64 108)
Mar 16 14:55:14 192.168.0.130 Mar 16 10:55:15 0023697DF435 OP:TIMEOU = 110 (120   40)
Mar 16 14:55:14 192.168.0.130 Mar 16 10:55:15 0023697DF435 OP:SIPCOR =   0 ( 1   28)
Mar 16 14:55:14 192.168.0.130 Mar 16 10:55:15 0023697DF435 OP:SIPCTS = 32 ( 32 572)
Mar 16 14:55:14 192.168.0.130 Mar 16 10:55:15 0023697DF435 OP:SIPSTS = 32 ( 32 3496)
Mar 16 14:55:14 192.168.0.130 Mar 16 10:55:15 0023697DF435 OP:SIPAUS =   4 ( 8 588)
Mar 16 14:55:14 192.168.0.130 Mar 16 10:55:15 0023697DF435 OP:SIPDLG = 10 ( 10 140)
Mar 16 14:55:14 192.168.0.130 Mar 16 10:55:15 0023697DF435 OP:SIPSES = 12 ( 12 8368)
Mar 16 14:55:14 192.168.0.130 Mar 16 10:55:15 0023697DF435 OP:SIPREG =   2 ( 4 452)
Mar 16 14:55:14 192.168.0.130 Mar 16 10:55:15 0023697DF435 OP:SIPLIN =   0 ( 2 140)
Mar 16 14:55:14 192.168.0.130 Mar 16 10:55:15 0023697DF435 OP:SUBDLG =   2 ( 2 6436)
Mar 16 14:55:14 192.168.0.130 Mar 16 10:55:15 0023697DF435 OP:STUNTS = 16 ( 16   68)
Mar 16 14:55:14 192.168.0.130 Mar 16 10:55:15 0023697DF435
Mar 16 14:57:25 192.168.0.130 Mar 16 10:57:26 0023697DF435 [0]Off Hook
Mar 16 14:57:31 192.168.0.130 Mar 16 10:57:32 0023697DF435 2. Report digit 1 (1)(40 ms)
Mar 16 14:57:31 192.168.0.130 Mar 16 10:57:32 0023697DF435 2. Report digit 9 (1)(40 ms)
Mar 16 14:57:31 192.168.0.130 Mar 16 10:57:32 0023697DF435 2. Report digit 5 (1)(40 ms)
Mar 16 14:57:32 192.168.0.130 Mar 16 10:57:33 0023697DF435 2. Report digit 1 (1)(40 ms)
Mar 16 14:57:32 192.168.0.130 Mar 16 10:57:33 0023697DF435 2. Report digit 8 (1)(40 ms)
Mar 16 14:57:32 192.168.0.130 Mar 16 10:57:33 0023697DF435 2. Report digit 2 (1)(40 ms)
Mar 16 14:57:32 192.168.0.130 Mar 16 10:57:33 0023697DF435 2. Report digit 3 (1)(40 ms)
Mar 16 14:57:33 192.168.0.130 Mar 16 10:57:34 0023697DF435 2. Report digit 1 (1)(40 ms)
Mar 16 14:57:33 192.168.0.130 Mar 16 10:57:34 0023697DF435 2. Report digit 3 (1)(40 ms)
Mar 16 14:57:33 192.168.0.130 Mar 16 10:57:34 0023697DF435 2. Report digit 0 (1)(40 ms)
Mar 16 14:57:34 192.168.0.130 Mar 16 10:57:34 0023697DF435 2. Report digit 0 (1)(40 ms)
Mar 16 14:57:34 192.168.0.130 Mar 16 10:57:35 0023697DF435 Calling:19518231300@toronto2.voip.ms:0
Mar 16 14:57:34 192.168.0.130 Mar 16 10:57:35 0023697DF435 [0:0]AUD ALLOC CALL (port=16386)
Mar 16 14:57:34 192.168.0.130 Mar 16 10:57:35 0023697DF435 [0:0]RTP Rx Up
Mar 16 14:57:34 192.168.0.130 Mar 16 10:57:35 0023697DF435 [0:0]AUD Rel Call
Mar 16 14:57:34 192.168.0.130 Mar 16 10:57:35 0023697DF435 CC:Failed w/ Calling
Mar 16 14:57:42 192.168.0.130 Mar 16 10:57:43 0023697DF435 [0]On Hook
Mar 16 14:57:46 192.168.0.130 Mar 16 10:57:47 0023697DF435 [0]Off Hook
Mar 16 14:57:49 192.168.0.130 Mar 16 10:57:50 0023697DF435 [0]On Hook
Mar 16 14:58:06 192.168.0.130 Mar 16 10:58:07 0023697DF435 Sess Terminated
Mar 16 14:58:19 192.168.0.130 Mar 16 10:58:20 0023697DF435
Mar 16 14:58:21 192.168.0.130 Mar 16 10:58:22 0023697DF435 CC:Clean Up
Mar 16 14:58:21 192.168.0.130 Mar 16 10:58:22 0023697DF435 --- OBJ POOL STAT ---
Mar 16 14:58:21 192.168.0.130 Mar 16 10:58:22 0023697DF435 OP:RTPRXB = 96 ( 96 192)
Mar 16 14:58:21 192.168.0.130 Mar 16 10:58:22 0023697DF435 OP:RTPREB = 40 ( 40   48)
Mar 16 14:58:21 192.168.0.130 Mar 16 10:58:22 0023697DF435 OP:RTPTXB = 64 ( 64 108)
Mar 16 14:58:21 192.168.0.130 Mar 16 10:58:22 0023697DF435 OP:TIMEOU = 107 (120   40)
Mar 16 14:58:21 192.168.0.130 Mar 16 10:58:22 0023697DF435 OP:SIPCOR =   0 ( 1   28)
Mar 16 14:58:21 192.168.0.130 Mar 16 10:58:22 0023697DF435 OP:SIPCTS = 31 ( 32 572)
Mar 16 14:58:21 192.168.0.130 Mar 16 10:58:22 0023697DF435 OP:SIPSTS = 32 ( 32 3496)
Mar 16 14:58:21 192.168.0.130 Mar 16 10:58:22 0023697DF435 OP:SIPAUS =   3 ( 8 588)
Mar 16 14:58:21 192.168.0.130 Mar 16 10:58:22 0023697DF435 OP:SIPDLG = 10 ( 10 140)
Mar 16 14:58:21 192.168.0.130 Mar 16 10:58:22 0023697DF435 OP:SIPSES = 12 ( 12 8368)
Mar 16 14:58:21 192.168.0.130 Mar 16 10:58:22 0023697DF435 OP:SIPREG =   2 ( 4 452)
Mar 16 14:58:21 192.168.0.130 Mar 16 10:58:22 0023697DF435 OP:SIPLIN =   0 ( 2 140)
Mar 16 14:58:21 192.168.0.130 Mar 16 10:58:22 0023697DF435 OP:SUBDLG =   2 ( 2 6436)
Mar 16 14:58:21 192.168.0.130 Mar 16 10:58:22 0023697DF435 OP:STUNTS = 16 ( 16   68)
Mar 16 14:58:21 192.168.0.130 Mar 16 10:58:22 0023697DF435

Daniele Giordano · ‎03-21-2011

As you can see in your log the call flow is as follows:

PAP sends INVITE

SIP PROVIDER responds with AUTHENTICATION REQUIRED

PAP sends INVITE+AUTH

SIP PROVIDER responds with 100 TRYING

SIP PROVIDER responds with 503 SERVICE UNAVAILABLE

Mar 21 09:52:10 192.168.0.130 Mar 21 09:52:09 0023697DF435 [0:5060]<<174.142.75.171:5060
Mar 21 09:52:10 192.168.0.130 Mar 21 09:52:09 0023697DF435 [0:5060]<<174.142.75.171:5060
Mar 21 09:52:10 192.168.0.130 Mar 21 09:52:09 0023697DF435 SIP/2.0 503 Service Unavailable Via: SIP/2.0/UDP 192.168.0.130:5060;branch=z9hG4bK-9b12a69f;received=99.254.11.249 From: <110600>;tag=387afbb5fba1393bo0 To: <19518231300>;tag=as462826c9 Call-ID: 2d7880bd-61637d3@192.168.0.130 CSeq: 102 INVITE User-Agent: VoIPMS/SERAST Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: <19518231300> Content-Length: 0

The problem is the response of the provider. A busy user must be signaled with 486 BUSY HERE.

Try to open a case with PROVIDER.

Regards.

View solution in original post

Daniele Giordano · ‎03-20-2011

Please enable SIP debug also and recall a busy user.

Post new logs.

We should see a SIP "486 busy here" message from your sip provider.

Thanks.

sammy_roplan · ‎03-21-2011

Hi Daniele,

I turned the SIP debug on to FULL, as well as the debug level to 99. I could not find any SIP 486 messages. Would this indicate a problem with my providers back-end?

Thanks..

Log:

Mar 21 09:51:58 192.168.0.130 Mar 21 09:51:58 0023697DF435
Mar 21 09:51:58 192.168.0.130 Mar 21 09:51:58 0023697DF435
Mar 21 09:52:01 192.168.0.130 Mar 21 09:52:02 0023697DF435 [0]Off Hook
Mar 21 09:52:05 192.168.0.130 Mar 21 09:52:06 0023697DF435 2. Report digit 1 (1)(40 ms)
Mar 21 09:52:05 192.168.0.130 Mar 21 09:52:06 0023697DF435 2. Report digit 9 (1)(40 ms)
Mar 21 09:52:05 192.168.0.130 Mar 21 09:52:06 0023697DF435 2. Report digit 5 (1)(40 ms)
Mar 21 09:52:05 192.168.0.130 Mar 21 09:52:06 0023697DF435 2. Report digit 1 (1)(40 ms)
Mar 21 09:52:06 192.168.0.130 Mar 21 09:52:07 0023697DF435 2. Report digit 8 (1)(40 ms)
Mar 21 09:52:06 192.168.0.130 Mar 21 09:52:07 0023697DF435 2. Report digit 2 (1)(40 ms)
Mar 21 09:52:06 192.168.0.130 Mar 21 09:52:07 0023697DF435 2. Report digit 3 (1)(40 ms)
Mar 21 09:52:06 192.168.0.130 Mar 21 09:52:08 0023697DF435 2. Report digit 1 (1)(40 ms)
Mar 21 09:52:07 192.168.0.130 Mar 21 09:52:08 0023697DF435 2. Report digit 3 (1)(40 ms)
Mar 21 09:52:07 192.168.0.130 Mar 21 09:52:08 0023697DF435 2. Report digit 0 (1)(40 ms)
Mar 21 09:52:07 192.168.0.130 Mar 21 09:52:08 0023697DF435 2. Report digit 0 (1)(40 ms)
Mar 21 09:52:07 192.168.0.130 Mar 21 09:52:09 0023697DF435 Calling:19518231300@174.142.75.171:0
Mar 21 09:52:07 192.168.0.130 Mar 21 09:52:09 0023697DF435 [0:0]AUD ALLOC CALL (port=16390)
Mar 21 09:52:08 192.168.0.130 Mar 21 09:52:09 0023697DF435 [0:0]RTP Rx Up
Mar 21 09:52:08 192.168.0.130 Mar 21 09:52:09 0023697DF435 [0:5060]->174.142.75.171:5060
Mar 21 09:52:08 192.168.0.130 Mar 21 09:52:09 0023697DF435 [0:5060]->174.142.75.171:5060
Mar 21 09:52:08 192.168.0.130 Mar 21 09:52:09 0023697DF435 INVITE sip:19518231300@174.142.75.171 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.130:5060;branch=z9hG4bK-30d48acb From: <110600>;tag=387afbb5fba1393bo0 To: <19518231300> Call-ID: 2d7880bd-61637d3@192.168.0.130 CSeq: 101 INVITE Max-Forwards: 70 Contact: <110600> Expires: 240 User-Agent: Linksys/PAP2T-5.1.6(LS) Content-Length: 253 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Supported: x-sipura, replaces Content-Type: application/sdp    v=0 o=- 22253 22253 IN IP4 192.168.0.130 s=- c=IN IP4 192.168.0.130 t=0 0 m=audio 16390 RTP/AVP 0 100 101 a=rtpmap:0 PCMU/8000 a=rtpmap:100 NSE/8000 a=fmtp:100 192-193 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=sendrecv
Mar 21 09:52:08 192.168.0.130 Mar 21 09:52:09 0023697DF435
Mar 21 09:52:08 192.168.0.130 Mar 21 09:52:09 0023697DF435
Mar 21 09:52:08 192.168.0.130 Mar 21 09:52:09 0023697DF435 [0:5060]<<174.142.75.171:5060
Mar 21 09:52:08 192.168.0.130 Mar 21 09:52:09 0023697DF435 [0:5060]<<174.142.75.171:5060
Mar 21 09:52:08 192.168.0.130 Mar 21 09:52:09 0023697DF435 SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 192.168.0.130:5060;branch=z9hG4bK-30d48acb;received=99.254.11.249 From: <110600>;tag=387afbb5fba1393bo0 To: <19518231300>;tag=as2e46967f Call-ID: 2d7880bd-61637d3@192.168.0.130 CSeq: 101 INVITE User-Agent: VoIPMS/SERAST Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Proxy-Authenticate: Digest algorithm=MD5, realm="montreal2.voip.ms", nonce="20b8be69" Content-Length: 0
Mar 21 09:52:08 192.168.0.130 Mar 21 09:52:09 0023697DF435
Mar 21 09:52:08 192.168.0.130 Mar 21 09:52:09 0023697DF435
Mar 21 09:52:08 192.168.0.130 Mar 21 09:52:09 0023697DF435 [0:5060]->174.142.75.171:5060
Mar 21 09:52:09 192.168.0.130 Mar 21 09:52:09 0023697DF435 [0:5060]->174.142.75.171:5060
Mar 21 09:52:09 192.168.0.130 Mar 21 09:52:09 0023697DF435 ACK sip:19518231300@174.142.75.171 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.130:5060;branch=z9hG4bK-30d48acb From: <110600>;tag=387afbb5fba1393bo0 To: <19518231300>;tag=as2e46967f Call-ID: 2d7880bd-61637d3@192.168.0.130 CSeq: 101 ACK Max-Forwards: 70 Contact: <110600> User-Agent: Linksys/PAP2T-5.1.6(LS) Content-Length: 0
Mar 21 09:52:09 192.168.0.130 Mar 21 09:52:09 0023697DF435
Mar 21 09:52:09 192.168.0.130 Mar 21 09:52:09 0023697DF435
Mar 21 09:52:09 192.168.0.130 Mar 21 09:52:09 0023697DF435 [0:5060]->174.142.75.171:5060
Mar 21 09:52:09 192.168.0.130 Mar 21 09:52:09 0023697DF435 [0:5060]->174.142.75.171:5060
Mar 21 09:52:09 192.168.0.130 Mar 21 09:52:09 0023697DF435 INVITE sip:19518231300@174.142.75.171 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.130:5060;branch=z9hG4bK-9b12a69f From: <110600>;tag=387afbb5fba1393bo0 To: <19518231300> Call-ID: 2d7880bd-61637d3@192.168.0.130 CSeq: 102 INVITE Max-Forwards: 70 Proxy-Authorization: Digest username="110600",realm="montreal2.voip.ms",nonce="20b8be69",uri="sip:19518231300@174.142.75.171",algorithm=MD5,response="85280e04e076328b5b6ecb45d0fc8f4f" Contact: <110600> Expires: 240 User-Agent: Linksys/PAP2T-5.1.6(LS) Content-Length: 253 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Supported: x-sipura, replaces Content-Type: application/sdp    v=0 o=- 22253 22253 IN IP4 192.168.0.130 s=- c=IN IP4 192.168.0.130 t=0 0 m=audio 16390 RTP/AVP 0 100 101 a=rtpmap:0 PCMU/8000 a=rtpmap:100 NSE/8000 a=fmtp:100 192-193 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=sendrecv
Mar 21 09:52:09 192.168.0.130 Mar 21 09:52:09 0023697DF435
Mar 21 09:52:09 192.168.0.130 Mar 21 09:52:09 0023697DF435
Mar 21 09:52:09 192.168.0.130 Mar 21 09:52:09 0023697DF435 [0:5060]<<174.142.75.171:5060
Mar 21 09:52:09 192.168.0.130 Mar 21 09:52:09 0023697DF435 [0:5060]<<174.142.75.171:5060
Mar 21 09:52:09 192.168.0.130 Mar 21 09:52:09 0023697DF435 SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.0.130:5060;branch=z9hG4bK-9b12a69f;received=99.254.11.249 From: <110600>;tag=387afbb5fba1393bo0 To: <19518231300> Call-ID: 2d7880bd-61637d3@192.168.0.130 CSeq: 102 INVITE User-Agent: VoIPMS/SERAST Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: <19518231300> Content-Length: 0
Mar 21 09:52:10 192.168.0.130 Mar 21 09:52:09 0023697DF435
Mar 21 09:52:10 192.168.0.130 Mar 21 09:52:09 0023697DF435
Mar 21 09:52:10 192.168.0.130 Mar 21 09:52:09 0023697DF435 [0:5060]<<174.142.75.171:5060
Mar 21 09:52:10 192.168.0.130 Mar 21 09:52:09 0023697DF435 [0:5060]<<174.142.75.171:5060
Mar 21 09:52:10 192.168.0.130 Mar 21 09:52:09 0023697DF435 SIP/2.0 503 Service Unavailable Via: SIP/2.0/UDP 192.168.0.130:5060;branch=z9hG4bK-9b12a69f;received=99.254.11.249 From: <110600>;tag=387afbb5fba1393bo0 To: <19518231300>;tag=as462826c9 Call-ID: 2d7880bd-61637d3@192.168.0.130 CSeq: 102 INVITE User-Agent: VoIPMS/SERAST Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: <19518231300> Content-Length: 0
Mar 21 09:52:10 192.168.0.130 Mar 21 09:52:09 0023697DF435
Mar 21 09:52:10 192.168.0.130 Mar 21 09:52:09 0023697DF435
Mar 21 09:52:10 192.168.0.130 Mar 21 09:52:09 0023697DF435 [0:5060]->174.142.75.171:5060
Mar 21 09:52:10 192.168.0.130 Mar 21 09:52:09 0023697DF435 [0:5060]->174.142.75.171:5060
Mar 21 09:52:10 192.168.0.130 Mar 21 09:52:09 0023697DF435 ACK sip:19518231300@174.142.75.171 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.130:5060;branch=z9hG4bK-9b12a69f From: <110600>;tag=387afbb5fba1393bo0 To: <19518231300>;tag=as462826c9 Call-ID: 2d7880bd-61637d3@192.168.0.130 CSeq: 102 ACK Max-Forwards: 70 Proxy-Authorization: Digest username="110600",realm="montreal2.voip.ms",nonce="20b8be69",uri="sip:19518231300@174.142.75.171",algorithm=MD5,response="85280e04e076328b5b6ecb45d0fc8f4f" Contact: <110600> User-Agent: Linksys/PAP2T-5.1.6(LS) Content-Length: 0
Mar 21 09:52:10 192.168.0.130 Mar 21 09:52:09 0023697DF435
Mar 21 09:52:10 192.168.0.130 Mar 21 09:52:09 0023697DF435
Mar 21 09:52:11 192.168.0.130 Mar 21 09:52:09 0023697DF435 [0:0]AUD Rel Call
Mar 21 09:52:11 192.168.0.130 Mar 21 09:52:09 0023697DF435 CC:Failed w/ Calling
Mar 21 09:52:12 192.168.0.130 Mar 21 09:52:13 0023697DF435 [0:5060]->174.142.75.171:5060
Mar 21 09:52:12 192.168.0.130 Mar 21 09:52:13 0023697DF435 [0:5060]->174.142.75.171:5060
Mar 21 09:52:12 192.168.0.130 Mar 21 09:52:13 0023697DF435 NOTIFY sip:174.142.75.171 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.130:5060;branch=z9hG4bK-efb67d1b From: <110600>;tag=ea1aaff9fef91b6fo0 To: <174.142.75.171> Call-ID: 95842da1-d47179e7@192.168.0.130 CSeq: 15 NOTIFY Max-Forwards: 70 Event: keep-alive User-Agent: Linksys/PAP2T-5.1.6(LS) Content-Length: 0
Mar 21 09:52:12 192.168.0.130 Mar 21 09:52:13 0023697DF435
Mar 21 09:52:12 192.168.0.130 Mar 21 09:52:13 0023697DF435
Mar 21 09:52:12 192.168.0.130 Mar 21 09:52:13 0023697DF435 [0:5060]<<174.142.75.171:5060
Mar 21 09:52:12 192.168.0.130 Mar 21 09:52:13 0023697DF435 [0:5060]<<174.142.75.171:5060
Mar 21 09:52:12 192.168.0.130 Mar 21 09:52:13 0023697DF435 SIP/2.0 489 Bad event Via: SIP/2.0/UDP 192.168.0.130:5060;branch=z9hG4bK-efb67d1b;received=99.254.11.249 From: <110600>;tag=ea1aaff9fef91b6fo0 To: <174.142.75.171>;tag=as6e989b3f Call-ID: 95842da1-d47179e7@192.168.0.130 CSeq: 15 NOTIFY User-Agent: VoIPMS/SERAST Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0
Mar 21 09:52:13 192.168.0.130 Mar 21 09:52:13 0023697DF435
Mar 21 09:52:13 192.168.0.130 Mar 21 09:52:13 0023697DF435
Mar 21 09:52:17 192.168.0.130 Mar 21 09:52:18 0023697DF435 [0]On Hook
Mar 21 09:52:22 192.168.0.130 Mar 21 09:52:23 0023697DF435 [0]Off Hook
Mar 21 09:52:24 192.168.0.130 Mar 21 09:52:26 0023697DF435 [0]On Hook
Mar 21 09:52:27 192.168.0.130 Mar 21 09:52:28 0023697DF435 [0:5060]->174.142.75.171:5060
Mar 21 09:52:27 192.168.0.130 Mar 21 09:52:28 0023697DF435 [0:5060]->174.142.75.171:5060
Mar 21 09:52:27 192.168.0.130 Mar 21 09:52:28 0023697DF435 NOTIFY sip:174.142.75.171 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.130:5060;branch=z9hG4bK-a3923eae From: <110600>;tag=ea1aaff9fef91b6fo0 To: <174.142.75.171> Call-ID: 95842da1-d47179e7@192.168.0.130 CSeq: 16 NOTIFY Max-Forwards: 70 Event: keep-alive User-Agent: Linksys/PAP2T-5.1.6(LS) Content-Length: 0
Mar 21 09:52:27 192.168.0.130 Mar 21 09:52:28 0023697DF435
Mar 21 09:52:27 192.168.0.130 Mar 21 09:52:28 0023697DF435
Mar 21 09:52:27 192.168.0.130 Mar 21 09:52:28 0023697DF435 [0:5060]<<174.142.75.171:5060
Mar 21 09:52:27 192.168.0.130 Mar 21 09:52:28 0023697DF435 [0:5060]<<174.142.75.171:5060
Mar 21 09:52:28 192.168.0.130 Mar 21 09:52:28 0023697DF435 SIP/2.0 489 Bad event Via: SIP/2.0/UDP 192.168.0.130:5060;branch=z9hG4bK-a3923eae;received=99.254.11.249 From: <110600>;tag=ea1aaff9fef91b6fo0 To: <174.142.75.171>;tag=as40bc8724 Call-ID: 95842da1-d47179e7@192.168.0.130 CSeq: 16 NOTIFY User-Agent: VoIPMS/SERAST Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0
Mar 21 09:52:28 192.168.0.130 Mar 21 09:52:28 0023697DF435
Mar 21 09:52:28 192.168.0.130 Mar 21 09:52:28 0023697DF435
Mar 21 09:52:40 192.168.0.130 Mar 21 09:52:41 0023697DF435 Sess Terminated
Mar 21 09:52:42 192.168.0.130 Mar 21 09:52:43 0023697DF435 [0:5060]->174.142.75.171:5060
Mar 21 09:52:42 192.168.0.130 Mar 21 09:52:43 0023697DF435 [0:5060]->174.142.75.171:5060
Mar 21 09:52:42 192.168.0.130 Mar 21 09:52:43 0023697DF435 NOTIFY sip:174.142.75.171 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.130:5060;branch=z9hG4bK-8289b817 From: <110600>;tag=ea1aaff9fef91b6fo0 To: <174.142.75.171> Call-ID: 95842da1-d47179e7@192.168.0.130 CSeq: 17 NOTIFY Max-Forwards: 70 Event: keep-alive User-Agent: Linksys/PAP2T-5.1.6(LS) Content-Length: 0
Mar 21 09:52:42 192.168.0.130 Mar 21 09:52:43 0023697DF435
Mar 21 09:52:42 192.168.0.130 Mar 21 09:52:43 0023697DF435
Mar 21 09:52:42 192.168.0.130 Mar 21 09:52:43 0023697DF435 [0:5060]<<174.142.75.171:5060
Mar 21 09:52:42 192.168.0.130 Mar 21 09:52:43 0023697DF435 [0:5060]<<174.142.75.171:5060
Mar 21 09:52:43 192.168.0.130 Mar 21 09:52:43 0023697DF435 SIP/2.0 489 Bad event Via: SIP/2.0/UDP 192.168.0.130:5060;branch=z9hG4bK-8289b817;received=99.254.11.249 From: <110600>;tag=ea1aaff9fef91b6fo0 To: <174.142.75.171>;tag=as416bd2ce Call-ID: 95842da1-d47179e7@192.168.0.130 CSeq: 17 NOTIFY User-Agent: VoIPMS/SERAST Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0
Mar 21 09:52:43 192.168.0.130 Mar 21 09:52:43 0023697DF435
Mar 21 09:52:43 192.168.0.130 Mar 21 09:52:43 0023697DF435
Mar 21 09:52:56 192.168.0.130 Mar 21 09:52:58 0023697DF435 CC:Clean Up
Mar 21 09:52:56 192.168.0.130 Mar 21 09:52:58 0023697DF435 --- OBJ POOL STAT ---
Mar 21 09:52:57 192.168.0.130 Mar 21 09:52:58 0023697DF435 OP:RTPRXB = 96 ( 96 192)
Mar 21 09:52:57 192.168.0.130 Mar 21 09:52:58 0023697DF435 OP:RTPREB = 40 ( 40   48)
Mar 21 09:52:57 192.168.0.130 Mar 21 09:52:58 0023697DF435 OP:RTPTXB = 64 ( 64 108)
Mar 21 09:52:57 192.168.0.130 Mar 21 09:52:58 0023697DF435 OP:TIMEOU = 110 (120   40)
Mar 21 09:52:57 192.168.0.130 Mar 21 09:52:58 0023697DF435 OP:SIPCOR =   0 ( 1   28)
Mar 21 09:52:57 192.168.0.130 Mar 21 09:52:58 0023697DF435 OP:SIPCTS = 32 ( 32 572)
Mar 21 09:52:57 192.168.0.130 Mar 21 09:52:58 0023697DF435 OP:SIPSTS = 32 ( 32 3496)
Mar 21 09:52:57 192.168.0.130 Mar 21 09:52:58 0023697DF435 OP:SIPAUS =   4 ( 8 588)
Mar 21 09:52:57 192.168.0.130 Mar 21 09:52:58 0023697DF435 OP:SIPDLG = 10 ( 10 140)
Mar 21 09:52:57 192.168.0.130 Mar 21 09:52:58 0023697DF435 OP:SIPSES = 12 ( 12 8368)
Mar 21 09:52:57 192.168.0.130 Mar 21 09:52:58 0023697DF435 OP:SIPREG =   2 ( 4 452)
Mar 21 09:52:57 192.168.0.130 Mar 21 09:52:58 0023697DF435 OP:SIPLIN =   0 ( 2 140)
Mar 21 09:52:58 192.168.0.130 Mar 21 09:52:58 0023697DF435 OP:SUBDLG =   2 ( 2 6436)
Mar 21 09:52:58 192.168.0.130 Mar 21 09:52:58 0023697DF435 OP:STUNTS = 16 ( 16   68)
Mar 21 09:52:58 192.168.0.130 Mar 21 09:52:58 0023697DF435
Mar 21 09:52:58 192.168.0.130 Mar 21 09:52:58 0023697DF435 [0:5060]->174.142.75.171:5060
Mar 21 09:52:58 192.168.0.130 Mar 21 09:52:58 0023697DF435 [0:5060]->174.142.75.171:5060
Mar 21 09:52:58 192.168.0.130 Mar 21 09:52:58 0023697DF435 NOTIFY sip:174.142.75.171 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.130:5060;branch=z9hG4bK-f431eba3 From: <110600>;tag=ea1aaff9fef91b6fo0 To: <174.142.75.171> Call-ID: 95842da1-d47179e7@192.168.0.130 CSeq: 18 NOTIFY Max-Forwards: 70 Event: keep-alive User-Agent: Linksys/PAP2T-5.1.6(LS) Content-Length: 0
Mar 21 09:52:58 192.168.0.130 Mar 21 09:52:58 0023697DF435
Mar 21 09:52:58 192.168.0.130 Mar 21 09:52:58 0023697DF435
Mar 21 09:52:58 192.168.0.130 Mar 21 09:52:58 0023697DF435 [0:5060]<<174.142.75.171:5060
Mar 21 09:52:58 192.168.0.130 Mar 21 09:52:58 0023697DF435 [0:5060]<<174.142.75.171:5060
Mar 21 09:52:58 192.168.0.130 Mar 21 09:52:58 0023697DF435 SIP/2.0 489 Bad event Via: SIP/2.0/UDP 192.168.0.130:5060;branch=z9hG4bK-f431eba3;received=99.254.11.249 From: <110600>;tag=ea1aaff9fef91b6fo0 To: <174.142.75.171>;tag=as48107130 Call-ID: 95842da1-d47179e7@192.168.0.130 CSeq: 18 NOTIFY User-Agent: VoIPMS/SERAST Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0
Mar 21 09:52:59 192.168.0.130 Mar 21 09:52:58 0023697DF435
Mar 21 09:52:59 192.168.0.130 Mar 21 09:52:58 0023697DF435

Daniele Giordano · ‎03-21-2011

As you can see in your log the call flow is as follows:

PAP sends INVITE

SIP PROVIDER responds with AUTHENTICATION REQUIRED

PAP sends INVITE+AUTH

SIP PROVIDER responds with 100 TRYING

SIP PROVIDER responds with 503 SERVICE UNAVAILABLE

Mar 21 09:52:10 192.168.0.130 Mar 21 09:52:09 0023697DF435 [0:5060]<<174.142.75.171:5060
Mar 21 09:52:10 192.168.0.130 Mar 21 09:52:09 0023697DF435 [0:5060]<<174.142.75.171:5060
Mar 21 09:52:10 192.168.0.130 Mar 21 09:52:09 0023697DF435 SIP/2.0 503 Service Unavailable Via: SIP/2.0/UDP 192.168.0.130:5060;branch=z9hG4bK-9b12a69f;received=99.254.11.249 From: <110600>;tag=387afbb5fba1393bo0 To: <19518231300>;tag=as462826c9 Call-ID: 2d7880bd-61637d3@192.168.0.130 CSeq: 102 INVITE User-Agent: VoIPMS/SERAST Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: <19518231300> Content-Length: 0

The problem is the response of the provider. A busy user must be signaled with 486 BUSY HERE.

Try to open a case with PROVIDER.

Regards.

sammy_roplan · ‎03-21-2011

Thanks for your input. I'll talk to my provider.