Topic: Extension shows busy straight off the bat

[peterpan746]

I have downloaded (Thursdayish)the latest (Version: sail-2.2.1-617)  SARK iso.  I have installed on testbed to see if I can get the BLF lights to work on a Snom 320.  The Snom registers 100% and also created extension for Zoiper (IAX) and placed the Zoiper extension on one of the Snom's function keys.  One thing that I did notice was that the Snom was sending out "Prov. Request" that was unsuccesful.

I did a "sip debug peer 5000" and made another call to the Snom.  Here is the output:

Code: [Select]

-- Called 5000
pbx1*CLI>
<--- SIP read from 192.168.1.101:2048 --->
SIP/2.0 486 Busy Here
Via: SIP/2.0/UDP 192.168.1.50:5060;branch=z9hG4bK429d100e;rport=5060
From: "5001" <sip:5001@192.168.1.50>;tag=as3f40aef7
To: <sip:5000@192.168.1.101:2048;line=7cfkokw4>;tag=aye6jqlzlw
Call-ID: 6cf9e38e2f790bb82485020f5316febe@192.168.1.50
CSeq: 102 INVITE
Contact: <sip:5000@192.168.1.101:2048;line=7cfkokw4>;reg-id=1
Content-Length: 0


<------------->
--- (8 headers 0 lines) ---
    -- Got SIP response 486 "Busy Here" back from 192.168.1.101
Transmitting (no NAT) to 192.168.1.101:2048:
ACK sip:5000@192.168.1.101:2048;line=7cfkokw4 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.50:5060;branch=z9hG4bK429d100e;rport
From: "5001" <sip:5001@192.168.1.50>;tag=as3f40aef7
To: <sip:5000@192.168.1.101:2048;line=7cfkokw4>;tag=aye6jqlzlw
Contact: <sip:5001@192.168.1.50>
Call-ID: 6cf9e38e2f790bb82485020f5316febe@192.168.1.50
CSeq: 102 ACK
User-Agent: Asterisk PBX
Max-Forwards: 70
Content-Length: 0


---
    -- SIP/5000-0942af48 is busy
  == Everyone is busy/congested at this time (1:1/0/0)
    -- AGI Script Executing Application: (Background) Options: (silence/1)
    -- <IAX2/5001-1> Playing 'silence/1' (language 'en')
Really destroying SIP dialog '6cf9e38e2f790bb82485020f5316febe@192.168.1.50' Method: INVITE
    -- AGI Script Executing Application: (Voicemail) Options: (5000|b)
    -- <IAX2/5001-1> Playing 'vm-theperson' (language 'en')
    -- <IAX2/5001-1> Playing 'digits/5' (language 'en')
  == Spawn extension (default, 5000, 1) exited non-zero on 'IAX2/5001-1'
    -- Executing [h@default:1] Hangup("IAX2/5001-1", "") in new stack
  == Spawn extension (default, h, 1) exited non-zero on 'IAX2/5001-1'
    -- Hungup 'IAX2/5001-1'
pbx1*CLI>
<--- SIP read from 192.168.1.101:2048 --->
REGISTER sip:192.168.1.50 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.101:2048;branch=z9hG4bK-4onn5i4rjcq1;rport
From: "5000" <sip:5000@192.168.1.50>;tag=phb99fjtvx
To: "5000" <sip:5000@192.168.1.50>
Call-ID: 3c2670616818-cqnt1qruslr2
CSeq: 23 REGISTER
Max-Forwards: 70
Contact: <sip:5000@192.168.1.101:2048;line=7cfkokw4>;reg-id=1;q=1.0;+sip.instance="<urn:uuid:8a98f0fb-e24b-406e-82d7-08552645cb02>";audio;mobility="fixed";duplex="full";description="snom320";actor="principal";events="dialog";methods="INVITE,ACK,CANCEL,BYE,REFER,OPTIONS,NOTIFY,SUBSCRIBE,PRACK,MESSAGE,INFO"
User-Agent: snom320/7.3.14
Supported: gruu
Allow-Events: dialog
X-Real-IP: 192.168.1.101
Expires: 3600
Content-Length: 0


<------------->
--- (14 headers 0 lines) ---
Using latest REGISTER request as basis request
Sending to 192.168.1.101 : 2048 (NAT)

<--- Transmitting (no NAT) to 192.168.1.101:2048 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.1.101:2048;branch=z9hG4bK-4onn5i4rjcq1;received=192.168.1.101;rport=2048
From: "5000" <sip:5000@192.168.1.50>;tag=phb99fjtvx
To: "5000" <sip:5000@192.168.1.50>
Call-ID: 3c2670616818-cqnt1qruslr2
CSeq: 23 REGISTER
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Contact: <sip:5000@192.168.1.50>
Content-Length: 0


<------------>

<--- Transmitting (no NAT) to 192.168.1.101:2048 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 192.168.1.101:2048;branch=z9hG4bK-4onn5i4rjcq1;received=192.168.1.101;rport=2048
From: "5000" <sip:5000@192.168.1.50>;tag=phb99fjtvx
To: "5000" <sip:5000@192.168.1.50>;tag=as47b2ce1a
Call-ID: 3c2670616818-cqnt1qruslr2
CSeq: 23 REGISTER
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="42b69ff0"
Content-Length: 0


<------------>
Scheduling destruction of SIP dialog '3c2670616818-cqnt1qruslr2' in 32000 ms (Method: REGISTER)
pbx1*CLI>
<--- SIP read from 192.168.1.101:2048 --->
REGISTER sip:192.168.1.50 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.101:2048;branch=z9hG4bK-agvzr4ngba5d;rport
From: "5000" <sip:5000@192.168.1.50>;tag=phb99fjtvx
To: "5000" <sip:5000@192.168.1.50>
Call-ID: 3c2670616818-cqnt1qruslr2
CSeq: 24 REGISTER
Max-Forwards: 70
Contact: <sip:5000@192.168.1.101:2048;line=7cfkokw4>;reg-id=1;q=1.0;+sip.instance="<urn:uuid:8a98f0fb-e24b-406e-82d7-08552645cb02>";audio;mobility="fixed";duplex="full";description="snom320";actor="principal";events="dialog";methods="INVITE,ACK,CANCEL,BYE,REFER,OPTIONS,NOTIFY,SUBSCRIBE,PRACK,MESSAGE,INFO"
User-Agent: snom320/7.3.14
Supported: gruu
Allow-Events: dialog
X-Real-IP: 192.168.1.101
Authorization: Digest username="5000",realm="asterisk",nonce="42b69ff0",uri="sip:192.168.1.50",response="9e152cd871458185fc38e7a1ab144313",algorithm=MD5
Expires: 3600
Content-Length: 0


<------------->
--- (15 headers 0 lines) ---
Using latest REGISTER request as basis request
Sending to 192.168.1.101 : 2048 (NAT)

<--- Transmitting (no NAT) to 192.168.1.101:2048 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.1.101:2048;branch=z9hG4bK-agvzr4ngba5d;received=192.168.1.101;rport=2048
From: "5000" <sip:5000@192.168.1.50>;tag=phb99fjtvx
To: "5000" <sip:5000@192.168.1.50>
Call-ID: 3c2670616818-cqnt1qruslr2
CSeq: 24 REGISTER
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Contact: <sip:5000@192.168.1.50>
Content-Length: 0


<------------>
pbx1*CLI>
<--- Transmitting (no NAT) to 192.168.1.101:2048 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.101:2048;branch=z9hG4bK-agvzr4ngba5d;received=192.168.1.101;rport=2048
From: "5000" <sip:5000@192.168.1.50>;tag=phb99fjtvx
To: "5000" <sip:5000@192.168.1.50>;tag=as47b2ce1a
Call-ID: 3c2670616818-cqnt1qruslr2
CSeq: 24 REGISTER
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Expires: 180
Contact: <sip:5000@192.168.1.101:2048;line=7cfkokw4>;expires=180
Date: Fri, 18 Sep 2009 21:40:55 GMT
Content-Length: 0


<------------>
Scheduling destruction of SIP dialog '3c2670616818-cqnt1qruslr2' in 32000 ms (Method: REGISTER)
Scheduling destruction of SIP dialog '4b79f40343e9e889756b054a421caeba@192.168.1.50' in 6400 ms (Method: NOTIFY)
Reliably Transmitting (no NAT) to 192.168.1.101:2048:
NOTIFY sip:5000@192.168.1.101:2048;line=7cfkokw4 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.50:5060;branch=z9hG4bK2c62f7a4;rport
From: "asterisk" <sip:asterisk@192.168.1.50>;tag=as572bb596
To: <sip:5000@192.168.1.101:2048;line=7cfkokw4>
Contact: <sip:asterisk@192.168.1.50>
Call-ID: 4b79f40343e9e889756b054a421caeba@192.168.1.50
CSeq: 102 NOTIFY
User-Agent: Asterisk PBX
Max-Forwards: 70
Event: message-summary
Content-Type: application/simple-message-summary
Content-Length: 92

Messages-Waiting: no
Message-Account: sip:asterisk@192.168.1.50
Voice-Message: 0/0 (0/0)

---
pbx1*CLI>
<--- SIP read from 192.168.1.101:2048 --->
SIP/2.0 200 Ok
Via: SIP/2.0/UDP 192.168.1.50:5060;branch=z9hG4bK2c62f7a4;rport=5060
From: "asterisk" <sip:asterisk@192.168.1.50>;tag=as572bb596
To: <sip:5000@192.168.1.101:2048;line=7cfkokw4>
Call-ID: 4b79f40343e9e889756b054a421caeba@192.168.1.50
CSeq: 102 NOTIFY
Content-Length: 0


<------------->
--- (7 headers 0 lines) ---
Really destroying SIP dialog '4b79f40343e9e889756b054a421caeba@192.168.1.50' Method: NOTIFY

What gets me is that even though the extension is free, it immediately shows busy.  Any suggestions?

Thanks in advance.

Frik

PS: I did upgrade on the existing software that was on the box.

[SARK devs]

I'm assuming you provisioned the phone manually...

From your trace, the phone really is giving back busy. 

check that it isn't in DND or forwarded to nowhere (both of these conditions will give back busy).

Kind Regards

S

[peterpan746]

It was as you suspected, the phone was fwd'ed to nowhere.

Like always you are a life saver.