Intermittent Inbound busy signal

Running Asterisk 1.6.2.17.2 on FreePBX 2.7.0.10

We have 2 in bound sipstation trunks, and 2 analog lines on a DADHI card. All inbound calls endup in our IVR regardless of source. Outbound calls are working just fine.

On occasion, and very randomly a call will come in from our sip trunk, get picked up by freepbx then goto a busy signal. I grabbed a few snippets from the logs, The first shows a call comming in and going to IVR.

[May 23 09:31:36] VERBOSE[3451] netsock.c:   == Using SIP RTP TOS bits 184
[May 23 09:31:36] VERBOSE[3451] netsock.c:   == Using SIP RTP CoS mark 5
[May 23 09:31:36] VERBOSE[31079] pbx.c:     -- Executing [<InboundPhoneNumber>@from-pstn:1] NoOp("SIP/fpbx-1-d62e8a55-00000242", "Catch-All DID Match - Found <InboundPhoneNumber> - You probably want a DID for this.") in new stack
[May 23 09:31:36] VERBOSE[31079] pbx.c:     -- Executing [<InboundPhoneNumber>@from-pstn:2] Goto("SIP/fpbx-1-d62e8a55-00000242", "ext-did,s,1") in new stack
[May 23 09:31:36] VERBOSE[31079] pbx.c:     -- Goto (ext-did,s,1)
[May 23 09:31:36] VERBOSE[31079] pbx.c:     -- Executing [[email protected]:1] Set("SIP/fpbx-1-d62e8a55-00000242", "__FROM_DID=s") in new stack
[May 23 09:31:36] VERBOSE[31079] pbx.c:     -- Executing [[email protected]:2] ExecIf("SIP/fpbx-1-d62e8a55-00000242", "0 ?Set(CALLERID(name)=+<MyMobileNumber>)") in new stack
[May 23 09:31:36] VERBOSE[31079] pbx.c:     -- Executing [[email protected]:3] SetMusicOnHold("SIP/fpbx-1-d62e8a55-00000242", "Other") in new stack
[May 23 09:31:36] VERBOSE[31079] pbx.c:     -- Executing [[email protected]:4] Set("SIP/fpbx-1-d62e8a55-00000242", "__MOHCLASS=Other") in new stack
[May 23 09:31:36] VERBOSE[31079] pbx.c:     -- Executing [[email protected]:5] Set("SIP/fpbx-1-d62e8a55-00000242", "__CALLINGPRES_SV=allowed_not_screened") in new stack
[May 23 09:31:36] VERBOSE[31079] pbx.c:     -- Executing [[email protected]:6] Set("SIP/fpbx-1-d62e8a55-00000242", "CALLERPRES()=allowed_not_screened") in new stack
[May 23 09:31:36] VERBOSE[31079] pbx.c:     -- Executing [[email protected]:7] Goto("SIP/fpbx-1-d62e8a55-00000242", "ivr-3,s,1") in new stack
[May 23 09:31:36] VERBOSE[31079] pbx.c:     -- Goto (ivr-3,s,1)
[May 23 09:31:36] VERBOSE[31079] pbx.c:     -- Executing [[email protected]:1] Set("SIP/fpbx-1-d62e8a55-00000242", "MSG=custom/MainGreeting") in new stack
[May 23 09:31:36] VERBOSE[31079] pbx.c:     -- Executing [[email protected]:2] Set("SIP/fpbx-1-d62e8a55-00000242", "LOOPCOUNT=0") in new stack
[May 23 09:31:36] VERBOSE[31079] pbx.c:     -- Executing [[email protected]:3] Set("SIP/fpbx-1-d62e8a55-00000242", "__DIR-CONTEXT=default") in new stack
[May 23 09:31:36] VERBOSE[31079] pbx.c:     -- Executing [[email protected]:4] Set("SIP/fpbx-1-d62e8a55-00000242", "_IVR_CONTEXT_ivr-3=") in new stack
[May 23 09:31:36] VERBOSE[31079] pbx.c:     -- Executing [[email protected]:5] Set("SIP/fpbx-1-d62e8a55-00000242", "_IVR_CONTEXT=ivr-3") in new stack
[May 23 09:31:36] VERBOSE[31079] pbx.c:     -- Executing [[email protected]:6] GotoIf("SIP/fpbx-1-d62e8a55-00000242", "0?begin") in new stack
[May 23 09:31:36] VERBOSE[31079] pbx.c:     -- Executing [[email protected]:7] Answer("SIP/fpbx-1-d62e8a55-00000242", "") in new stack
[May 23 09:31:37] VERBOSE[31079] pbx.c:     -- Executing [[email protected]:8] Wait("SIP/fpbx-1-d62e8a55-00000242", "1") in new stack
[May 23 09:31:38] VERBOSE[31079] pbx.c:     -- Executing [[email protected]:9] Set("SIP/fpbx-1-d62e8a55-00000242", "TIMEOUT(digit)=3") in new stack
[May 23 09:31:38] VERBOSE[31079] func_timeout.c:     -- Digit timeout set to 3.000
[May 23 09:31:38] VERBOSE[31079] pbx.c:     -- Executing [[email protected]:10] Set("SIP/fpbx-1-d62e8a55-00000242", "TIMEOUT(response)=10") in new stack
[May 23 09:31:38] VERBOSE[31079] func_timeout.c:     -- Response timeout set to 10.000
[May 23 09:31:38] VERBOSE[31079] pbx.c:     -- Executing [[email protected]:11] Set("SIP/fpbx-1-d62e8a55-00000242", "__IVR_RETVM=") in new stack
[May 23 09:31:38] VERBOSE[31079] pbx.c:     -- Executing [[email protected]:12] ExecIf("SIP/fpbx-1-d62e8a55-00000242", "1?Background(custom/MainGreeting)") in new stack
[May 23 09:31:38] VERBOSE[31079] file.c:     -- <SIP/fpbx-1-d62e8a55-00000242> Playing 'custom/MainGreeting.slin' (language 'en')
[May 23 09:31:43] VERBOSE[31079] pbx.c:   == Spawn extension (ivr-3, s, 12) exited non-zero on 'SIP/fpbx-1-d62e8a55-00000242'
[May 23 09:31:43] VERBOSE[31079] pbx.c:     -- Executing [[email protected]:1] Hangup("SIP/fpbx-1-d62e8a55-00000242", "") in new stack
[May 23 09:31:43] VERBOSE[31079] pbx.c:   == Spawn extension (ivr-3, h, 1) exited non-zero on 'SIP/fpbx-1-d62e8a55-00000242'

This shows call that went to busy signal after a few rings.

[May 23 09:30:40] VERBOSE[3451] netsock.c:   == Using SIP RTP TOS bits 184
[May 23 09:30:40] VERBOSE[3451] netsock.c:   == Using SIP RTP CoS mark 5
[May 23 09:30:45] VERBOSE[31067] pbx.c:     -- Executing [<InboundPhoneNumber>@from-pstn:1] NoOp("SIP/fpbx-1-d62e8a55-00000241", "Catch-All DID Match - Found <InboundPhoneNumber> - You probably want a DID for this.") in new stack
[May 23 09:30:45] VERBOSE[31067] pbx.c:     -- Executing [<InboundPhoneNumber>@from-pstn:2] Goto("SIP/fpbx-1-d62e8a55-00000241", "ext-did,s,1") in new stack
[May 23 09:30:45] VERBOSE[31067] pbx.c:     -- Goto (ext-did,s,1)
[May 23 09:30:45] VERBOSE[31067] pbx.c:     -- Executing [[email protected]:1] Set("SIP/fpbx-1-d62e8a55-00000241", "__FROM_DID=s") in new stack
[May 23 09:30:45] VERBOSE[31067] pbx.c:     -- Executing [[email protected]:2] ExecIf("SIP/fpbx-1-d62e8a55-00000241", "0 ?Set(CALLERID(name)=+<MyMobileNumber>)") in new stack
[May 23 09:30:45] VERBOSE[31067] pbx.c:     -- Executing [[email protected]:3] SetMusicOnHold("SIP/fpbx-1-d62e8a55-00000241", "Other") in new stack
[May 23 09:30:45] VERBOSE[31067] pbx.c:     -- Executing [[email protected]:4] Set("SIP/fpbx-1-d62e8a55-00000241", "__MOHCLASS=Other") in new stack
[May 23 09:30:45] VERBOSE[31067] pbx.c:     -- Executing [[email protected]:5] Set("SIP/fpbx-1-d62e8a55-00000241", "__CALLINGPRES_SV=allowed_not_screened") in new stack
[May 23 09:30:45] VERBOSE[31067] pbx.c:     -- Executing [[email protected]:6] Set("SIP/fpbx-1-d62e8a55-00000241", "CALLERPRES()=allowed_not_screened") in new stack
[May 23 09:30:45] VERBOSE[31067] pbx.c:     -- Executing [[email protected]:7] Goto("SIP/fpbx-1-d62e8a55-00000241", "ivr-3,s,1") in new stack
[May 23 09:30:45] VERBOSE[31067] pbx.c:     -- Goto (ivr-3,s,1)
[May 23 09:30:45] VERBOSE[31067] pbx.c:     -- Executing [[email protected]:1] Set("SIP/fpbx-1-d62e8a55-00000241", "MSG=custom/MainGreeting") in new stack
[May 23 09:30:45] VERBOSE[31067] pbx.c:     -- Executing [[email protected]:2] Set("SIP/fpbx-1-d62e8a55-00000241", "LOOPCOUNT=0") in new stack
[May 23 09:30:45] VERBOSE[31067] pbx.c:     -- Executing [[email protected]:3] Set("SIP/fpbx-1-d62e8a55-00000241", "__DIR-CONTEXT=default") in new stack
[May 23 09:30:45] VERBOSE[31067] pbx.c:     -- Executing [[email protected]:4] Set("SIP/fpbx-1-d62e8a55-00000241", "_IVR_CONTEXT_ivr-3=") in new stack
[May 23 09:30:45] VERBOSE[31067] pbx.c:     -- Executing [[email protected]:5] Set("SIP/fpbx-1-d62e8a55-00000241", "_IVR_CONTEXT=ivr-3") in new stack
[May 23 09:30:45] VERBOSE[31067] pbx.c:     -- Executing [[email protected]:6] GotoIf("SIP/fpbx-1-d62e8a55-00000241", "0?begin") in new stack
[May 23 09:30:45] VERBOSE[31067] pbx.c:     -- Executing [[email protected]:7] Answer("SIP/fpbx-1-d62e8a55-00000241", "") in new stack
[May 23 09:30:45] VERBOSE[31067] pbx.c:   == Spawn extension (ivr-3, s, 7) exited non-zero on 'SIP/fpbx-1-d62e8a55-00000241'
[May 23 09:30:45] VERBOSE[31067] pbx.c:     -- Executing [[email protected]:1] Hangup("SIP/fpbx-1-d62e8a55-00000241", "") in new stack
[May 23 09:30:45] VERBOSE[31067] pbx.c:   == Spawn extension (ivr-3, h, 1) exited non-zero on 'SIP/fpbx-1-d62e8a55-00000241'

Any ideas of what might be causing this?

After additional testing it appears that the line will only report a busy signal on the first call, the second and any subsequent calls coming in over the next few minutes are fine. So i’m thinking that this is some sort of a SIP trunk issue.

Here is one of our peer records for our SIP trunk.


disallow=all
allow=ulaw
context=from-pstn&from-pstn
type=peer
insecure=very
qualify=yes
sendrpid=yes
trustrpid=yes
dtmfmode=rfc2833
username=<USER>
secret=<PW>
host=trunk1.phonebooth.net

I am having the same issue.

Were you ever able to isolate the cause? I was thinking it was with the two routes setup (trunk1.phonebooth.net vs. trunk2.phonebooth.net). When I would see these calls in the call report, trunk2 always seemed to be the working trunk 98% of the time, so I disabled trunk1. However, I just experienced the same problem with only trunk2 enabled.

Ended up changing SIP Providers and that seems to have fixed it.

Who did you switch to?

Switched to bandwidth.com they own sipstation but it’s a seperate business unit. Got much better support from them as well.

http://bandwidth.com/sip-trunking/