Strange Problem

dhancock777 · January 31, 2013, 11:46pm

I have a user at an extension (ext28) that can call other users on the network and can make external calls via the dial out trunk. Here’s the weird part: external phones have no problems calling that extension, and soft SIP phones (like blink) can dial internally. However, I’ve had no success with internal hardware phones (Linksys SPA921) to extension 28. The user gets a busy signal, and a SIP debug dump shows sip udp packets to/from registering to 0.

<— SIP read from UDP:10.x.x.x:5060 —>
INVITE sip:[email protected] SIP/2.0^M
Via: SIP/2.0/UDP 10.x.x.x:5060;branch=z9hG4bK-d1edd40^M
From: “dhancock777” sip:[email protected];tag=6316693c58f5afe0o0^M
To: sip:[email protected]^M
Call-ID: [email protected]^M
CSeq: 101 INVITE^M
Max-Forwards: 70^M
Contact: “Dan Hancock” sip:[email protected]:5060

So I can see where the problem is but I’m at a loss to figure out how to fix this. I know that it’s not a hardware issue as I’ve swapped out his phone and/or tried ext28 on different Linksys or Cisco devices. I’ve also tried deleting and recreating the extension with no success. Changing his extension works, but this solution isn’t viable since he has business cards that include ext28 for the contact number. Some info:

Asterisk 1.6.2.11
FreePBX 2.7.0

Span 1: WCTDM/0 “Wildcard AEX800 Board 1” (MASTER)

fxsks=1
echocanceller=mg2,1
fxsks=2
echocanceller=mg2,2
fxsks=3
echocanceller=mg2,3
fxsks=4
echocanceller=mg2,4

channel 5, WCTDM/0/4, no module.

channel 6, WCTDM/0/5, no module.

channel 7, WCTDM/0/6, no module.

channel 8, WCTDM/0/7, no module.

dhancock777 · February 5, 2013, 6:00pm

No ideas? I’m unsure if there is a rogue extension setting that is messing up my internal forwarding or what…

w5waf · February 5, 2013, 6:55pm

Years ago, in my early days of asterisk. 9 or 10 years ago…I seem to remember a constraint against using 2 digit extension numbers. All I kind of remember is that it might cause unpredictable results. Never thought much about it because I’ve stuck with 3 or 4 digit extensions.

BF

leemason · February 5, 2013, 7:56pm

I’m using 2 digit extension numbers with no problem. I’ve been doing it for years and have had no issues (in the range 5x).

lgaetz · February 5, 2013, 9:07pm

If softphones can dial 28 and hardphones can’t, it is probably the digit map (dial pattern) of the phones.

dhancock777 · February 5, 2013, 9:54pm

Thanks for the replies so far.

I currently have 45 extensions, all double digits. Aside from ext#28, each of these can call each other from hardware or software phones. What I find strange is that ext#28 call call other internal extensions but not vice versa.

@lgaetz: Care to explain more? All extensions can dial internally and externally fine. Hardware phones can’t call ext#28, but ext#28 can dial other extensions fine.

artarzi · February 5, 2013, 10:28pm

After saying your extensions are in the range 5x you assigned 28 to this one - any reason?
If you are getting a “dial” in the log then the phones are pushing it through, otherwise - it’s the phones

w5waf · February 5, 2013, 10:43pm

What I said was, that years ago there was a warning that in SOME cases, 2 Digit extensions can behave in an unpredictable manner. You may have hit on that unusual combo. Don’t know.

Is the phone registered?

What does “sip show peers like 28” show from the * CLI.

BF

w5waf · February 5, 2013, 10:47pm

One other thought. Is “28” the same make and model with the same FW as the other phones?
BF

dhancock777 · February 5, 2013, 11:46pm

pbx1*CLI> sip show peers like 28
Name/username Host Dyn Nat ACL Port Status
28/28 10.1.66.141 D N A 5060 OK (19 ms)
1 sip peers [Monitored: 1 online, 0 offline Unmonitored: 0 online, 0 offline]

pbx1*CLI> sip show channels
Peer User/ANR Call ID Format Hold Last Message Expiry
10.1.66.141 (None) 7cd209a9-617a0f 0x0 (nothing) No Rx: REGISTER

pbx1*CLI> sip show user 28

Name : 28
Secret :
MD5Secret :
Context : from-internal
Language :
AMA flags : Unknown
Transfer mode: open
MaxCallBR : 384 kbps
CallingPres : Presentation Allowed, Not Screened
Call limit : 50
Callgroup :
Pickupgroup :
Callerid : “device” <28>
ACL : Yes
Sess-Timers : Accept
Sess-Refresh : uas
Sess-Expires : 1800 secs
Sess-Min-SE : 90 secs
Codec Order : (ulaw:20,alaw:20)
Auto-Framing: No

Same Linksys SPA921 for all devices. I’m convinced that there is something buried in the extension config files but as of yet I have been unable to find it.

@Bill: On a side note, I recently traveled to Vicksburg, MS to repair a server after a RAID failure. Nice city, though I didn’t have much time to sight see.

w5waf · February 6, 2013, 3:33am

If you ever get this way again, let me know. We’ll have to get together. I’m in downtown Vicksburg at city hall.

BF

w5waf · February 6, 2013, 3:46am

Dan…

I guess no one has asked the obvious question…What happens when someone calls 28. And what do you see in the logs?

BF

dhancock777 · February 6, 2013, 8:30pm

I dumped a bit if the sip debug that I had running in my first post but I can submit more if that helps. Whenever an internal (hardware) extension tries calling ext28 they immediately get a busy signal. From what I can see, asterisk sends a SIP invite to the server ([email protected]) and then immediately initiates hangup. Excerpt from the logs:


Connected to Asterisk 1.6.2.11 currently running on pbx1 (pid = 3065)

Verbosity is at least 3

== Using SIP RTP TOS bits 184

== Using SIP RTP CoS mark 5

– Executing [0@from-internal:1] Macro(“SIP/44-00000696”, “user-callerid,SKIPTTL,”) in new stack

– Executing [s@macro-user-callerid:1] Set(“SIP/44-00000696”, “AMPUSER=44”) in new stack

– Executing [s@macro-user-callerid:2] GotoIf(“SIP/44-00000696”, “0?report”) in new stack

– Executing [s@macro-user-callerid:3] ExecIf(“SIP/44-00000696”, “1?Set(REALCALLERIDNUM=44)”) in new stack

– Executing [s@macro-user-callerid:4] Set(“SIP/44-00000696”, “AMPUSER=44”) in new stack

– Executing [s@macro-user-callerid:5] Set(“SIP/44-00000696”, “AMPUSERCIDNAME=Dan Hancock”) in new stack

– Executing [s@macro-user-callerid:6] GotoIf(“SIP/44-00000696”, “0?report”) in new stack

– Executing [s@macro-user-callerid:7] Set(“SIP/44-00000696”, “AMPUSERCID=44”) in new stack

– Executing [s@macro-user-callerid:8] Set(“SIP/44-00000696”, “CALLERID(all)=“Dan Hancock” <44>”) in new stack

– Executing [s@macro-user-callerid:9] GotoIf(“SIP/44-00000696”, “1?continue”) in new stack

– Goto (macro-user-callerid,s,18)

– Executing [s@macro-user-callerid:18] NoOp(“SIP/44-00000696”, “Using CallerID “Dan Hancock” <44>”) in new stack

– Auto fallthrough, channel ‘SIP/44-00000696’ status is ‘UNKNOWN’

– Executing [h@from-internal:1] Macro(“SIP/44-00000696”, “hangupcall”) in new stack

– Executing [s@macro-hangupcall:1] GotoIf(“SIP/44-00000696”, “1?skiprg”) in new stack

– Goto (macro-hangupcall,s,4)

– Executing [s@macro-hangupcall:4] GotoIf(“SIP/44-00000696”, “1?skipblkvm”) in new stack

– Goto (macro-hangupcall,s,7)

– Executing [s@macro-hangupcall:7] GotoIf(“SIP/44-00000696”, “1?theend”) in new stack

– Goto (macro-hangupcall,s,9)

– Executing [s@macro-hangupcall:9] Hangup(“SIP/44-00000696”, “”) in new stack

== Spawn extension (macro-hangupcall, s, 9) exited non-zero on ‘SIP/44-00000696’ in macro ‘hangupcall’

== Spawn extension (from-internal, h, 1) exited non-zero on ‘SIP/44-00000696’

dhancock777 · February 6, 2013, 8:32pm

The above is my hardware phone (Linksys SPA921) extension#44 calling extension#28 (which is the same model phone).

w5waf · February 6, 2013, 10:28pm

On another, not 28, phone…In the “Dial Plan” section, set the “Dial Plan” field to “[x*].” (without the quotes) and see what happens when you use that phone to call 28.

BF

dhancock777 · February 8, 2013, 7:00pm

Attached is the output of my extension calling #28 after changing the dial plan from “SIP/44” to “[x*].” in the freepbx panel. I immediately get a busy signal when trying to call #28 but not with any other extensions or dialing out.

From asterisk CLI panel (from #44 to #28):
Using SIP RTP TOS bits 184 == Using SIP RTP CoS mark 5 – Executing [0@from-internal:1] Macro(“SIP/44-000006f7”, “user-callerid,SKIPTTL,”) in new stack – Executing [s@macro-user-callerid:1] Set(“SIP/44-000006f7”, “AMPUSER=44”) in new stack – Executing [s@macro-user-callerid:2] GotoIf(“SIP/44-000006f7”, “0?report”) in new stack – Executing [s@macro-user-callerid:3] ExecIf(“SIP/44-000006f7”, “1?Set(REALCALLERIDNUM=44)”) in new stack – Executing [s@macro-user-callerid:4] Set(“SIP/44-000006f7”, “AMPUSER=44”) in new stack – Executing [s@macro-user-callerid:5] Set(“SIP/44-000006f7”, “AMPUSERCIDNAME=Dan Hancock”) in new stack – Executing [s@macro-user-callerid:6] GotoIf(“SIP/44-000006f7”, “0?report”) in new stack – Executing [s@macro-user-callerid:7] Set(“SIP/44-000006f7”, “AMPUSERCID=44”) in new stack – Executing [s@macro-user-callerid:8] Set(“SIP/44-000006f7”, “CALLERID(all)=“Dan Hancock” <44>”) in new stack – Executing [s@macro-user-callerid:9] GotoIf(“SIP/44-000006f7”, “1?continue”) in new stack – Goto (macro-user-callerid,s,18) – Executing [s@macro-user-callerid:18] NoOp(“SIP/44-000006f7”, “Using CallerID “Dan Hancock” <44>”) in new stack – Auto fallthrough, channel ‘SIP/44-000006f7’ status is ‘UNKNOWN’ – Executing [h@from-internal:1] Macro(“SIP/44-000006f7”, “hangupcall”) in new stack – Executing [s@macro-hangupcall:1] GotoIf(“SIP/44-000006f7”, “1?skiprg”) in new stack – Goto (macro-hangupcall,s,4) – Executing [s@macro-hangupcall:4] GotoIf(“SIP/44-000006f7”, “1?skipblkvm”) in new stack – Goto (macro-hangupcall,s,7) – Executing [s@macro-hangupcall:7] GotoIf(“SIP/44-000006f7”, “1?theend”) in new stack – Goto (macro-hangupcall,s,9) – Executing [s@macro-hangupcall:9] Hangup(“SIP/44-000006f7”, “”) in new stack == Spawn extension (macro-hangupcall, s, 9) exited non-zero on ‘SIP/44-000006f7’ in macro ‘hangupcall’ == Spawn extension (from-internal, h, 1) exited non-zero on ‘SIP/44-000006f7’

To another internal extension (#23) from my extension #44:


 == Using SIP RTP TOS bits 184
  == Using SIP RTP CoS mark 5
    -- Executing [23@from-internal:1] Macro("SIP/44-000006f9", "exten-vm,23,23") in new stack
    -- Executing [s@macro-exten-vm:1] Macro("SIP/44-000006f9", "user-callerid,") in new stack
    -- Executing [s@macro-user-callerid:1] Set("SIP/44-000006f9", "AMPUSER=44") in new stack
    -- Executing [s@macro-user-callerid:2] GotoIf("SIP/44-000006f9", "0?report") in new stack
    -- Executing [s@macro-user-callerid:3] ExecIf("SIP/44-000006f9", "1?Set(REALCALLERIDNUM=44)") in new stack
    -- Executing [s@macro-user-callerid:4] Set("SIP/44-000006f9", "AMPUSER=44") in new stack
    -- Executing [s@macro-user-callerid:5] Set("SIP/44-000006f9", "AMPUSERCIDNAME=Dan Hancock") in new stack
    -- Executing [s@macro-user-callerid:6] GotoIf("SIP/44-000006f9", "0?report") in new stack
    -- Executing [s@macro-user-callerid:7] Set("SIP/44-000006f9", "AMPUSERCID=44") in new stack
    -- Executing [s@macro-user-callerid:8] Set("SIP/44-000006f9", "CALLERID(all)="Dan Hancock" <44>") in new stack
    -- Executing [s@macro-user-callerid:9] GotoIf("SIP/44-000006f9", "0?continue") in new stack
    -- Executing [s@macro-user-callerid:10] Set("SIP/44-000006f9", "__TTL=64") in new stack
    -- Executing [s@macro-user-callerid:11] GotoIf("SIP/44-000006f9", "1?continue") in new stack
    -- Goto (macro-user-callerid,s,18)
    -- Executing [s@macro-user-callerid:18] NoOp("SIP/44-000006f9", "Using CallerID "Dan Hancock" <44>") in new stack
    -- Executing [s@macro-exten-vm:2] Set("SIP/44-000006f9", "RingGroupMethod=none") in new stack
    -- Executing [s@macro-exten-vm:3] Set("SIP/44-000006f9", "VMBOX=23") in new stack
    -- Executing [s@macro-exten-vm:4] Set("SIP/44-000006f9", "EXTTOCALL=23") in new stack
    -- Executing [s@macro-exten-vm:5] Set("SIP/44-000006f9", "CFUEXT=") in new stack
    -- Executing [s@macro-exten-vm:6] Set("SIP/44-000006f9", "CFBEXT=") in new stack
    -- Executing [s@macro-exten-vm:7] Set("SIP/44-000006f9", "RT=15") in new stack
    -- Executing [s@macro-exten-vm:8] Macro("SIP/44-000006f9", "record-enable,23,IN") in new stack
    -- Executing [s@macro-record-enable:1] GotoIf("SIP/44-000006f9", "1?check") in new stack
    -- Goto (macro-record-enable,s,4)
    -- Executing [s@macro-record-enable:4] ExecIf("SIP/44-000006f9", "0?MacroExit()") in new stack
    -- Executing [s@macro-record-enable:5] GotoIf("SIP/44-000006f9", "0?Group:OUT") in new stack
    -- Goto (macro-record-enable,s,16)
    -- Executing [s@macro-record-enable:16] GotoIf("SIP/44-000006f9", "1?IN") in new stack
    -- Goto (macro-record-enable,s,21)
    -- Executing [s@macro-record-enable:21] ExecIf("SIP/44-000006f9", "1?MacroExit()") in new stack
    -- Executing [s@macro-exten-vm:9] Macro("SIP/44-000006f9", "dial,15,tr,23") in new stack
    -- Executing [s@macro-dial:1] GotoIf("SIP/44-000006f9", "1?dial") in new stack
    -- Goto (macro-dial,s,3)
    -- Executing [s@macro-dial:3] AGI("SIP/44-000006f9", "dialparties.agi") in new stack
    -- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
 dialparties.agi: Starting New Dialparties.agi
 dialparties.agi: Caller ID name is 'Dan Hancock' number is '44'
 dialparties.agi: Methodology of ring is  'none'
    -- dialparties.agi: Added extension 23 to extension map
    -- dialparties.agi: Extension 23 cf is disabled
    -- dialparties.agi: Extension 23 do not disturb is disabled
 dialparties.agi: EXTENSION_STATE: 0 (NOT_INUSE)
    -- dialparties.agi: dbset CALLTRACE/23 to 44
    -- dialparties.agi: Filtered ARG3: 23
    -- AGI Script dialparties.agi completed, returning 0
    -- Executing [s@macro-dial:7] Dial("SIP/44-000006f9", "SIP/23,15,tr") in new stack
  == Using SIP RTP TOS bits 184
  == Using SIP RTP CoS mark 5
    -- Called 23
    -- SIP/23-000006fa is ringing
  == Spawn extension (macro-dial, s, 7) exited non-zero on 'SIP/44-000006f9' in macro 'dial'
  == Spawn extension (macro-exten-vm, s, 9) exited non-zero on 'SIP/44-000006f9' in macro 'exten-vm'
  == Spawn extension (from-internal, 23, 1) exited non-zero on 'SIP/44-000006f9'
    -- Executing [h@from-internal:1] Macro("SIP/44-000006f9", "hangupcall") in new stack
    -- Executing [s@macro-hangupcall:1] GotoIf("SIP/44-000006f9", "1?skiprg") in new stack
    -- Goto (macro-hangupcall,s,4)
    -- Executing [s@macro-hangupcall:4] GotoIf("SIP/44-000006f9", "1?skipblkvm") in new stack
    -- Goto (macro-hangupcall,s,7)
    -- Executing [s@macro-hangupcall:7] GotoIf("SIP/44-000006f9", "1?theend") in new stack
    -- Goto (macro-hangupcall,s,9)
    -- Executing [s@macro-hangupcall:9] Hangup("SIP/44-000006f9", "") in new stack
  == Spawn extension (macro-hangupcall, s, 9) exited non-zero on 'SIP/44-000006f9' in macro 'hangupcall'
  == Spawn extension (from-internal, h, 1) exited non-zero on 'SIP/44-000006f9'

Again I appreciate the time and help.