Incoming calls get 'not in service' message

I’m at a loss here. Outbound calls work fine. Inbound calls get not in service message.

I have seven trunks set up, each for a separate area code plus an 8xx toll free. Each trunk is set up for outbound and inbound calls. I have inbound routes set for each number (trunk). Each inbound route has the DID set to the phone number and is sent to a ring group. Only other option set is the DID name prefix.

One thing I find strange is that when calling the 8xx number it uses the 347 incoming route instead of the 8xx route. I’ve included a sip debug below.

Any help is appreciated.

[2014-05-08 07:08:15] Asterisk 11.7.0 built by root @ jenkins-el6-64.schmoozecom.net on a x86_64 running Linux on 2014-01-07 00:10:47 UTC
[2014-05-08 07:08:15] VERBOSE[10384] config.c: == Parsing ‘/etc/asterisk/logger.conf’: Found
[2014-05-08 07:08:15] VERBOSE[10384] config.c: == Parsing ‘/etc/asterisk/logger_general_additional.conf’: Found
[2014-05-08 07:08:15] VERBOSE[10384] config.c: == Parsing ‘/etc/asterisk/logger_general_custom.conf’: Found
[2014-05-08 07:08:15] VERBOSE[10384] config.c: == Parsing ‘/etc/asterisk/logger_logfiles_additional.conf’: Found
[2014-05-08 07:08:15] VERBOSE[10384] config.c: == Parsing ‘/etc/asterisk/logger_logfiles_custom.conf’: Found
[2014-05-08 07:08:15] VERBOSE[10384] logger.c: Asterisk Queue Logger restarted
[2014-05-08 07:08:27] VERBOSE[19423] chan_sip.c:
ÿ<— SIP read from UDP:xx.23.129.253:5060 —>
ÿINVITE sip:[email protected] SIP/2.0
ÿRecord-Route: sip:[email protected]:5060;nat=yes;ftag=gK02515cfe;lr=on
ÿVia: SIP/2.0/UDP xx.23.129.253:5060;branch=z9hG4bKa2f9.81f92492.0
ÿVia: SIP/2.0/UDP xx.23.190.10:5060;branch=z9hG4bKa2f9.7bde33e4.0
ÿVia: SIP/2.0/UDP 4.55.42.35:5060;branch=z9hG4bK02B685233773ba5b546
ÿFrom: sip:[email protected]:5060;isup-oli=62;tag=gK02515cfe
ÿTo: sip:[email protected]:5060
ÿCall-ID: [email protected]
ÿCSeq: 4358 INVITE
ÿMax-Forwards: 15
ÿAllow: INVITE,ACK,CANCEL,BYE,REFER,SUBSCRIBE,PRACK,UPDATE
ÿAccept: application/sdp, application/isup, application/dtmf, application/dtmf-relay, multipart/mixed
ÿContact: sip:[email protected]:5060
ÿP-Asserted-Identity: sip:[email protected]:5060
ÿSupported: 100rel
ÿContent-Length: 300
ÿContent-Disposition: session; handling=required
ÿContent-Type: application/sdp
ÿ
ÿv=0
ÿo=Sonus_UAC 611 16926 IN IP4 4.55.42.35
ÿs=SIP Media Capabilities
ÿc=IN IP4 4.55.42.6
ÿt=0 0
ÿm=audio 13890 RTP/AVP 0 8 18 101
ÿa=rtpmap:0 PCMU/8000
ÿa=rtpmap:8 PCMA/8000
ÿa=rtpmap:18 G729/8000
ÿa=fmtp:18 annexb=no
ÿa=rtpmap:101 telephone-event/8000
ÿa=fmtp:101 0-15
ÿa=sendrecv
ÿa=maxptime:20
ÿ<------------->
[2014-05-08 07:08:27] VERBOSE[19423] chan_sip.c: — (18 headers 14 lines) —
[2014-05-08 07:08:27] VERBOSE[19423] chan_sip.c: Sending to xx.23.129.253:5060 (NAT)
[2014-05-08 07:08:27] VERBOSE[19423][C-000e3ee4] chan_sip.c: Sending to xx.23.129.253:5060 (NAT)
[2014-05-08 07:08:27] VERBOSE[19423][C-000e3ee4] chan_sip.c: Using INVITE request as basis request - [email protected]
[2014-05-08 07:08:27] VERBOSE[19423][C-000e3ee4] chan_sip.c: Found peer ‘nv_347’ for ‘+1630234xxxx’ from xx.23.129.253:5060
[2014-05-08 07:08:27] VERBOSE[19423][C-000e3ee4] netsock2.c: == Using SIP RTP TOS bits 184
[2014-05-08 07:08:27] VERBOSE[19423][C-000e3ee4] netsock2.c: == Using SIP RTP CoS mark 5
[2014-05-08 07:08:27] VERBOSE[19423][C-000e3ee4] chan_sip.c: Found RTP audio format 0
[2014-05-08 07:08:27] VERBOSE[19423][C-000e3ee4] chan_sip.c: Found RTP audio format 8
[2014-05-08 07:08:27] VERBOSE[19423][C-000e3ee4] chan_sip.c: Found RTP audio format 18
[2014-05-08 07:08:27] VERBOSE[19423][C-000e3ee4] chan_sip.c: Found RTP audio format 101
[2014-05-08 07:08:27] VERBOSE[19423][C-000e3ee4] chan_sip.c: Found audio description format PCMU for ID 0
[2014-05-08 07:08:27] VERBOSE[19423][C-000e3ee4] chan_sip.c: Found audio description format PCMA for ID 8
[2014-05-08 07:08:27] VERBOSE[19423][C-000e3ee4] chan_sip.c: Found audio description format G729 for ID 18
[2014-05-08 07:08:27] VERBOSE[19423][C-000e3ee4] chan_sip.c: Found audio description format telephone-event for ID 101
[2014-05-08 07:08:27] VERBOSE[19423][C-000e3ee4] chan_sip.c: Capabilities: us - (gsm|ulaw|alaw|speex), peer - audio=(ulaw|alaw|g729)/video=(nothing)/text=(nothing), combined - (ulaw|alaw)
[2014-05-08 07:08:27] VERBOSE[19423][C-000e3ee4] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
[2014-05-08 07:08:27] VERBOSE[19423][C-000e3ee4] chan_sip.c: Peer audio RTP is at port 4.55.42.6:13890
[2014-05-08 07:08:27] VERBOSE[19423][C-000e3ee4] chan_sip.c: Looking for 18xx854xxxx in from-trunk-sip-nv_347 (domain xx.185.20.250)
[2014-05-08 07:08:27] VERBOSE[19423][C-000e3ee4] chan_sip.c: list_route: hop: sip:[email protected]:5060;nat=yes;ftag=gK02515cfe;lr=on
[2014-05-08 07:08:27] VERBOSE[19423][C-000e3ee4] chan_sip.c:
ÿ<— Transmitting (NAT) to xx.23.129.253:5060 —>
ÿSIP/2.0 100 Trying
ÿVia: SIP/2.0/UDP xx.23.129.253:5060;branch=z9hG4bKa2f9.81f92492.0;received=xx.23.129.253;rport=5060
ÿVia: SIP/2.0/UDP xx.23.190.10:5060;branch=z9hG4bKa2f9.7bde33e4.0
ÿVia: SIP/2.0/UDP 4.55.42.35:5060;branch=z9hG4bK02B685233773ba5b546
ÿRecord-Route: sip:[email protected]:5060;nat=yes;ftag=gK02515cfe;lr=on
ÿFrom: sip:[email protected]:5060;isup-oli=62;tag=gK02515cfe
ÿTo: sip:[email protected]:5060
ÿCall-ID: [email protected]
ÿCSeq: 4358 INVITE
ÿServer: FPBX-2.11.0(11.7.0)
ÿAllow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
ÿSupported: replaces, timer
ÿContact: sip:[email protected]:5060
ÿContent-Length: 0
ÿ
ÿ
ÿ<------------>
[2014-05-08 07:08:27] VERBOSE[10469][C-000e3ee4] pbx.c: – Executing [[email protected]_347:1] Set(“SIP/nv_347-000e45d4”, “GROUP()=OUT_6”) in new stack
[2014-05-08 07:08:27] VERBOSE[10469][C-000e3ee4] pbx.c: – Executing [[email protected]_347:2] Goto(“SIP/nv_347-000e45d4”, “from-trunk,18xx854xxxx,1”) in new stack
[2014-05-08 07:08:27] VERBOSE[10469][C-000e3ee4] pbx.c: – Goto (from-trunk,18xx854xxxx,1)
[2014-05-08 07:08:27] VERBOSE[10469][C-000e3ee4] pbx.c: – Executing [[email protected]:1] Set(“SIP/nv_347-000e45d4”, “__FROM_DID=18xx854xxxx”) in new stack
[2014-05-08 07:08:27] VERBOSE[10469][C-000e3ee4] pbx.c: – Executing [[email protected]:2] NoOp(“SIP/nv_347-000e45d4”, “Received an unknown call with DID set to 18xx854xxxx”) in new stack
[2014-05-08 07:08:27] VERBOSE[10469][C-000e3ee4] pbx.c: – Executing [[email protected]:3] Goto(“SIP/nv_347-000e45d4”, “s,a2”) in new stack
[2014-05-08 07:08:27] VERBOSE[10469][C-000e3ee4] pbx.c: – Goto (from-trunk,s,2)
[2014-05-08 07:08:27] VERBOSE[10469][C-000e3ee4] pbx.c: – Executing [[email protected]:2] Answer(“SIP/nv_347-000e45d4”, “”) in new stack
[2014-05-08 07:08:27] VERBOSE[10469][C-000e3ee4] chan_sip.c: Audio is at 10222
[2014-05-08 07:08:27] VERBOSE[10469][C-000e3ee4] chan_sip.c: Adding codec 100003 (ulaw) to SDP
[2014-05-08 07:08:27] VERBOSE[10469][C-000e3ee4] chan_sip.c: Adding codec 100004 (alaw) to SDP
[2014-05-08 07:08:27] VERBOSE[10469][C-000e3ee4] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP
[2014-05-08 07:08:27] VERBOSE[10469][C-000e3ee4] chan_sip.c:
ÿ<— Reliably Transmitting (NAT) to xx.23.129.253:5060 —>
ÿSIP/2.0 200 OK
ÿVia: SIP/2.0/UDP xx.23.129.253:5060;branch=z9hG4bKa2f9.81f92492.0;received=xx.23.129.253;rport=5060
ÿVia: SIP/2.0/UDP xx.23.190.10:5060;branch=z9hG4bKa2f9.7bde33e4.0
ÿVia: SIP/2.0/UDP 4.55.42.35:5060;branch=z9hG4bK02B685233773ba5b546
ÿRecord-Route: sip:[email protected]:5060;nat=yes;ftag=gK02515cfe;lr=on
ÿFrom: sip:[email protected]:5060;isup-oli=62;tag=gK02515cfe
ÿTo: sip:[email protected]:5060;tag=as682381d8
ÿCall-ID: [email protected]
ÿCSeq: 4358 INVITE
ÿServer: FPBX-2.11.0(11.7.0)
ÿAllow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
ÿSupported: replaces, timer
ÿContact: sip:[email protected]:5060
ÿContent-Type: application/sdp
ÿContent-Length: 261
ÿ
ÿv=0
ÿo=root 1671060948 1671060948 IN IP4 xx.185.20.250
ÿs=Asterisk PBX 11.7.0
ÿc=IN IP4 xx.185.20.250
ÿt=0 0
ÿm=audio 10222 RTP/AVP 0 8 101
ÿa=rtpmap:0 PCMU/8000
ÿa=rtpmap:8 PCMA/8000
ÿa=rtpmap:101 telephone-event/8000
ÿa=fmtp:101 0-16
ÿa=ptime:20
ÿa=sendrecv
ÿ
ÿ<------------>
[2014-05-08 07:08:27] VERBOSE[19423] chan_sip.c:
ÿ<— SIP read from UDP:xx.23.129.253:5060 —>
ÿACK sip:[email protected]:5060 SIP/2.0
ÿRecord-Route: sip:[email protected]:5060;nat=yes;ftag=gK02515cfe;lr=on
ÿVia: SIP/2.0/UDP xx.23.129.253:5060;branch=0
ÿVia: SIP/2.0/UDP 4.55.42.35:5060;branch=z9hG4bK02B6856153ec754625a
ÿFrom: sip:[email protected]:5060;isup-oli=62;tag=gK02515cfe
ÿTo: sip:[email protected]:5060;tag=as682381d8
ÿCall-ID: [email protected]
ÿCSeq: 4358 ACK
ÿMax-Forwards: 69
ÿContent-Length: 0
ÿ
ÿ<------------->
[2014-05-08 07:08:27] VERBOSE[19423] chan_sip.c: — (10 headers 0 lines) —
[2014-05-08 07:08:27] VERBOSE[10469][C-000e3ee4] pbx.c: – Executing [[email protected]:3] Wait(“SIP/nv_347-000e45d4”, “2”) in new stack
[2014-05-08 07:08:29] VERBOSE[10469][C-000e3ee4] pbx.c: – Executing [[email protected]:4] Playback(“SIP/nv_347-000e45d4”, “ss-noservice”) in new stack
[2014-05-08 07:08:29] VERBOSE[10469][C-000e3ee4] file.c: – <SIP/nv_347-000e45d4> Playing ‘ss-noservice.ulaw’ (language ‘en’)
[2014-05-08 07:08:34] VERBOSE[10469][C-000e3ee4] pbx.c: – Executing [[email protected]:5] SayAlpha(“SIP/nv_347-000e45d4”, “18xx854xxxx”) in new stack
[2014-05-08 07:08:34] VERBOSE[10469][C-000e3ee4] file.c: – <SIP/nv_347-000e45d4> Playing ‘digits/1.ulaw’ (language ‘en’)
[2014-05-08 07:08:35] VERBOSE[10469][C-000e3ee4] file.c: – <SIP/nv_347-000e45d4> Playing ‘digits/8.ulaw’ (language ‘en’)
[2014-05-08 07:08:35] VERBOSE[10469][C-000e3ee4] file.c: – <SIP/nv_347-000e45d4> Playing ‘digits/6.ulaw’ (language ‘en’)
[2014-05-08 07:08:36] VERBOSE[10469][C-000e3ee4] file.c: – <SIP/nv_347-000e45d4> Playing ‘digits/6.ulaw’ (language ‘en’)
[2014-05-08 07:08:37] VERBOSE[10469][C-000e3ee4] file.c: – <SIP/nv_347-000e45d4> Playing ‘digits/8.ulaw’ (language ‘en’)
[2014-05-08 07:08:37] VERBOSE[10469][C-000e3ee4] file.c: – <SIP/nv_347-000e45d4> Playing ‘digits/5.ulaw’ (language ‘en’)
[2014-05-08 07:08:38] VERBOSE[10469][C-000e3ee4] file.c: – <SIP/nv_347-000e45d4> Playing ‘digits/4.ulaw’ (language ‘en’)
[2014-05-08 07:08:38] VERBOSE[19219] asterisk.c: – Remote UNIX connection
[2014-05-08 07:08:38] VERBOSE[10633] asterisk.c: – Remote UNIX connection disconnected
[2014-05-08 07:08:39] VERBOSE[10469][C-000e3ee4] file.c: – <SIP/nv_347-000e45d4> Playing ‘digits/7.ulaw’ (language ‘en’)
[2014-05-08 07:08:39] VERBOSE[19423] chan_sip.c:
ÿ<— SIP read from UDP:98.197.92.59:33889 —>
ÿ
ÿ
ÿ<------------->
[2014-05-08 07:08:39] VERBOSE[10469][C-000e3ee4] file.c: – <SIP/nv_347-000e45d4> Playing ‘digits/4.ulaw’ (language ‘en’)
[2014-05-08 07:08:40] VERBOSE[10469][C-000e3ee4] file.c: – <SIP/nv_347-000e45d4> Playing ‘digits/7.ulaw’ (language ‘en’)
[2014-05-08 07:08:41] VERBOSE[10469][C-000e3ee4] file.c: – <SIP/nv_347-000e45d4> Playing ‘digits/8.ulaw’ (language ‘en’)
[2014-05-08 07:08:41] VERBOSE[10469][C-000e3ee4] pbx.c: – Executing [[email protected]:6] Hangup(“SIP/nv_347-000e45d4”, “”) in new stack
[2014-05-08 07:08:41] VERBOSE[10469][C-000e3ee4] pbx.c: == Spawn extension (from-trunk, s, 6) exited non-zero on ‘SIP/nv_347-000e45d4’
[2014-05-08 07:08:41] VERBOSE[10469][C-000e3ee4] pbx.c: – Executing [[email protected]:1] Macro(“SIP/nv_347-000e45d4”, “hangupcall,”) in new stack
[2014-05-08 07:08:41] VERBOSE[10469][C-000e3ee4] pbx.c: – Executing [[email protected]:1] GotoIf(“SIP/nv_347-000e45d4”, “1?theend”) in new stack
[2014-05-08 07:08:41] VERBOSE[10469][C-000e3ee4] pbx.c: – Goto (macro-hangupcall,s,3)
[2014-05-08 07:08:41] VERBOSE[10469][C-000e3ee4] pbx.c: – Executing [[email protected]:3] ExecIf(“SIP/nv_347-000e45d4”, “0?Set(CDR(recordingfile)=)”) in new stack
[2014-05-08 07:08:41] VERBOSE[10469][C-000e3ee4] pbx.c: – Executing [[email protected]:4] Hangup(“SIP/nv_347-000e45d4”, “”) in new stack
[2014-05-08 07:08:41] VERBOSE[10469][C-000e3ee4] app_macro.c: == Spawn extension (macro-hangupcall, s, 4) exited non-zero on ‘SIP/nv_347-000e45d4’ in macro ‘hangupcall’
[2014-05-08 07:08:41] VERBOSE[10469][C-000e3ee4] pbx.c: == Spawn extension (from-trunk, h, 1) exited non-zero on ‘SIP/nv_347-000e45d4’
[2014-05-08 07:08:41] VERBOSE[10469][C-000e3ee4] chan_sip.c: Scheduling destruction of SIP dialog ‘[email protected]’ in 32000 ms (Method: ACK)
[2014-05-08 07:08:41] VERBOSE[10469][C-000e3ee4] chan_sip.c: set_destination: Parsing sip:[email protected]:5060;nat=yes;ftag=gK02515cfe;lr=on for address/port to send to
[2014-05-08 07:08:41] VERBOSE[10469][C-000e3ee4] chan_sip.c: set_destination: set destination to xx.23.129.253:5060
[2014-05-08 07:08:41] VERBOSE[10469][C-000e3ee4] chan_sip.c: Reliably Transmitting (NAT) to xx.23.129.253:5060:
ÿBYE sip:[email protected]:5060 SIP/2.0
ÿVia: SIP/2.0/UDP xx.185.20.250:5060;branch=z9hG4bK7abddd60;rport
ÿRoute: sip:[email protected]:5060;nat=yes;ftag=gK02515cfe;lr=on
ÿMax-Forwards: 70
ÿFrom: sip:[email protected]:5060;tag=as682381d8
ÿTo: sip:[email protected]:5060;isup-oli=62;tag=gK02515cfe
ÿCall-ID: [email protected]
ÿCSeq: 102 BYE
ÿUser-Agent: FPBX-2.11.0(11.7.0)
ÿX-Asterisk-HangupCause: Normal Clearing
ÿX-Asterisk-HangupCauseCode: 16
ÿContent-Length: 0
ÿ
ÿ
ÿ—
[2014-05-08 07:08:41] VERBOSE[19423] chan_sip.c:
ÿ<— SIP read from UDP:xx.23.129.253:5060 —>
ÿSIP/2.0 200 OK
ÿVia: SIP/2.0/UDP xx.185.20.250:5060;branch=z9hG4bK7abddd60;rport=5060
ÿFrom: sip:[email protected]:5060;tag=as682381d8
ÿTo: sip:[email protected]:5060;isup-oli=62;tag=gK02515cfe
ÿCall-ID: [email protected]
ÿCSeq: 102 BYE
ÿRecord-Route: sip:[email protected]:5060;nat=yes;ftag=as682381d8;lr=on
ÿContent-Length: 0
ÿ
ÿ<------------->
[2014-05-08 07:08:41] VERBOSE[19423] chan_sip.c: — (8 headers 0 lines) —
[2014-05-08 07:08:41] VERBOSE[19423][C-000e3ee4] chan_sip.c: SIP Response message for INCOMING dialog BYE arrived
[2014-05-08 07:08:41] VERBOSE[19423] chan_sip.c: Really destroying SIP dialog ‘[email protected]’ Method: ACK
[2014-05-08 07:08:43] VERBOSE[19423] chan_sip.c: Really destroying SIP dialog ‘[email protected]’ Method: BYE

"Received an unknown call with DID set to 18xx854xxxx")

Adding a 1 to the DID field for the inbound route seemed to make this work much better.

Thanks.