The number you have dialed is not in service

Suddenly I’m having a problem where incoming calls get the message: “the number you have dialed is not in service”. The incoming route is set up to check for office hours and then go to a queue. When I call in to the lines, the queue starts for a fraction of a second then I get “the number you have dialed is not in service”

My Setup is:

  1. All PSTN analog lines going to Gransgream GXW4108.
  2. From there in FreePBX I have trunks for each line and an inbound route for each physical line too.

Without any changes to my system (no updates or anything), this started happening.

  • I have my setup on a Virtual machine and just to see I rolled back my system to previous images I had and the problem seemed to persist.
  • I have two phone lines going through the same setup but from different phone numbers and the calls get passed on fine. The only difference is that they go to an IVR instead of a queue.
  • I tried changing the inbound routes to accept calls from any DID (previously they were set up with specific DID taht was transmitted from the GXW4108), but to no avail.
  • I have change the setting in SIP settings to allow calls from anonymous

From time to time the calls go through, and then they don’t. I have noticed that I get “congested” as an item on the logfiles, but I don;t know what it means.

Here is the logfile right after a failed inbound call… Any suggestions appreciated…

[2015-04-28 16:20:00] VERBOSE[2661] pbx_spool.c: -- Attempting call on Local/[email protected] for application NoCDR() (Retry 1)
[2015-04-28 16:20:00] VERBOSE[2661] pbx_spool.c: -- Attempting call on Local/[email protected] for application NoCDR() (Retry 1)
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:1] NoCDR("Local/[email protected];2", "") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:1] NoCDR("Local/[email protected];2", "") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:2] Set("Local/[email protected];2", "TCMAINT=RETURN") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:2] Set("Local/[email protected];2", "TCMAINT=RETURN") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:3] Gosub("Local/[email protected];2", "timeconditions,3,1()") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:3] Gosub("Local/[email protected];2", "timeconditions,3,1()") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:1] Set("Local/[email protected];2", "DB(TC/3/INUSESTATE)=INUSE") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:1] Set("Local/[email protected];2", "DB(TC/3/INUSESTATE)=INUSE") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:2] Set("Local/[email protected];2", "DB(TC/3/NOT_INUSESTATE)=NOT_INUSE") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:2] Set("Local/[email protected];2", "DB(TC/3/NOT_INUSESTATE)=NOT_INUSE") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:3] GotoIfTime("Local/[email protected];2", "*,*,9,mar?truestate") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:3] GotoIfTime("Local/[email protected];2", "*,*,9,mar?truestate") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:4] GotoIfTime("Local/[email protected];2", "*,*,6,apr?truestate") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:4] GotoIfTime("Local/[email protected];2", "*,*,6,apr?truestate") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:5] GotoIfTime("Local/[email protected];2", "*,*,3,apr?truestate") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:5] GotoIfTime("Local/[email protected];2", "*,*,3,apr?truestate") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:6] GotoIfTime("Local/[email protected];2", "*,*,3-5,aug?truestate") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:6] GotoIfTime("Local/[email protected];2", "*,*,3-5,aug?truestate") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:7] GotoIfTime("Local/[email protected];2", "*,*,2,mar?truestate") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:7] GotoIfTime("Local/[email protected];2", "*,*,2,mar?truestate") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:8] GotoIfTime("Local/[email protected];2", "*,*,29,jun?truestate") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:8] GotoIfTime("Local/[email protected];2", "*,*,29,jun?truestate") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:9] GotoIfTime("Local/[email protected];2", "*,*,25,may?truestate") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:9] GotoIfTime("Local/[email protected];2", "*,*,25,may?truestate") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:10] GotoIfTime("Local/[email protected];2", "*,*,1,jan?truestate") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:10] GotoIfTime("Local/[email protected];2", "*,*,1,jan?truestate") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:11] GotoIfTime("Local/[email protected];2", "*,*,19,oct?truestate") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:11] GotoIfTime("Local/[email protected];2", "*,*,19,oct?truestate") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:12] GotoIfTime("Local/[email protected];2", "*,*,13,jun?truestate") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:12] GotoIfTime("Local/[email protected];2", "*,*,13,jun?truestate") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:13] GotoIfTime("Local/[email protected];2", "*,*,25-28,dec?truestate") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:13] GotoIfTime("Local/[email protected];2", "*,*,25-28,dec?truestate") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:14] GotoIf("Local/[email protected];2", "0?truegoto") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:14] GotoIf("Local/[email protected];2", "0?truegoto") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:15] ExecIf("Local/[email protected];2", "0?Set(DB(TC/3)=)") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:15] ExecIf("Local/[email protected];2", "0?Set(DB(TC/3)=)") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:16] Set("Local/[email protected];2", "DEVICE_STATE(Custom:TC3)=INUSE") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:16] Set("Local/[email protected];2", "DEVICE_STATE(Custom:TC3)=INUSE") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:17] ExecIf("Local/[email protected];2", "0?Set(DEVICE_STATE(Custom:TCSTICKY)=INUSE)") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:17] ExecIf("Local/[email protected];2", "0?Set(DEVICE_STATE(Custom:TCSTICKY)=INUSE)") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:18] GotoIf("Local/[email protected];2", "0?timeconditions,1,1") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:18] GotoIf("Local/[email protected];2", "0?timeconditions,1,1") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:19] Set("Local/[email protected];2", "TCSTATE=false") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:19] Set("Local/[email protected];2", "TCSTATE=false") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:20] Set("Local/[email protected];2", "TCOVERRIDE=false") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:20] Set("Local/[email protected];2", "TCOVERRIDE=false") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:21] Return("Local/[email protected];2", "") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:21] Return("Local/[email protected];2", "") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:4] System("Local/[email protected];2", "/var/lib/asterisk/bin/schedtc.php 60 /var/spool/asterisk/outgoing 0") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:4] System("Local/[email protected];2", "/var/lib/asterisk/bin/schedtc.php 60 /var/spool/asterisk/outgoing 0") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:5] Answer("Local/[email protected];2", "") in new stack
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: -- Executing [[email protected]:5] Answer("Local/[email protected];2", "") in new stack
[2015-04-28 16:20:00] NOTICE[2661] pbx_spool.c: Call completed to Local/[email protected]
[2015-04-28 16:20:00] NOTICE[2661] pbx_spool.c: Call completed to Local/[email protected]
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: == Spawn extension (tc-maint, s, 5) exited non-zero on 'Local/[email protected];2'
[2015-04-28 16:20:00] VERBOSE[2662] pbx.c: == Spawn extension (tc-maint, s, 5) exited non-zero on 'Local/[email protected];2'
[2015-04-28 16:21:00] VERBOSE[2697] pbx_spool.c: -- Attempting call on Local/[email protected] for application NoCDR() (Retry 1)
[2015-04-28 16:21:00] VERBOSE[2697] pbx_spool.c: -- Attempting call on Local/[email protected] for application NoCDR() (Retry 1)
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:1] NoCDR("Local/[email protected];2", "") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:1] NoCDR("Local/[email protected];2", "") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:2] Set("Local/[email protected];2", "TCMAINT=RETURN") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:2] Set("Local/[email protected];2", "TCMAINT=RETURN") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:3] Gosub("Local/[email protected];2", "timeconditions,3,1()") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:3] Gosub("Local/[email protected];2", "timeconditions,3,1()") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:1] Set("Local/[email protected];2", "DB(TC/3/INUSESTATE)=INUSE") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:1] Set("Local/[email protected];2", "DB(TC/3/INUSESTATE)=INUSE") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:2] Set("Local/[email protected];2", "DB(TC/3/NOT_INUSESTATE)=NOT_INUSE") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:2] Set("Local/[email protected];2", "DB(TC/3/NOT_INUSESTATE)=NOT_INUSE") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:3] GotoIfTime("Local/[email protected];2", "*,*,9,mar?truestate") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:3] GotoIfTime("Local/[email protected];2", "*,*,9,mar?truestate") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:4] GotoIfTime("Local/[email protected];2", "*,*,6,apr?truestate") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:4] GotoIfTime("Local/[email protected];2", "*,*,6,apr?truestate") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:5] GotoIfTime("Local/[email protected];2", "*,*,3,apr?truestate") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:5] GotoIfTime("Local/[email protected];2", "*,*,3,apr?truestate") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:6] GotoIfTime("Local/[email protected];2", "*,*,3-5,aug?truestate") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:6] GotoIfTime("Local/[email protected];2", "*,*,3-5,aug?truestate") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:7] GotoIfTime("Local/[email protected];2", "*,*,2,mar?truestate") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:7] GotoIfTime("Local/[email protected];2", "*,*,2,mar?truestate") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:8] GotoIfTime("Local/[email protected];2", "*,*,29,jun?truestate") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:8] GotoIfTime("Local/[email protected];2", "*,*,29,jun?truestate") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:9] GotoIfTime("Local/[email protected];2", "*,*,25,may?truestate") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:9] GotoIfTime("Local/[email protected];2", "*,*,25,may?truestate") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:10] GotoIfTime("Local/[email protected];2", "*,*,1,jan?truestate") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:10] GotoIfTime("Local/[email protected];2", "*,*,1,jan?truestate") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:11] GotoIfTime("Local/[email protected];2", "*,*,19,oct?truestate") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:11] GotoIfTime("Local/[email protected];2", "*,*,19,oct?truestate") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:12] GotoIfTime("Local/[email protected];2", "*,*,13,jun?truestate") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:12] GotoIfTime("Local/[email protected];2", "*,*,13,jun?truestate") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:13] GotoIfTime("Local/[email protected];2", "*,*,25-28,dec?truestate") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:13] GotoIfTime("Local/[email protected];2", "*,*,25-28,dec?truestate") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:14] GotoIf("Local/[email protected];2", "0?truegoto") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:14] GotoIf("Local/[email protected];2", "0?truegoto") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:15] ExecIf("Local/[email protected];2", "0?Set(DB(TC/3)=)") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:15] ExecIf("Local/[email protected];2", "0?Set(DB(TC/3)=)") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:16] Set("Local/[email protected];2", "DEVICE_STATE(Custom:TC3)=INUSE") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:16] Set("Local/[email protected];2", "DEVICE_STATE(Custom:TC3)=INUSE") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:17] ExecIf("Local/[email protected];2", "0?Set(DEVICE_STATE(Custom:TCSTICKY)=INUSE)") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:17] ExecIf("Local/[email protected];2", "0?Set(DEVICE_STATE(Custom:TCSTICKY)=INUSE)") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:18] GotoIf("Local/[email protected];2", "0?timeconditions,1,1") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:18] GotoIf("Local/[email protected];2", "0?timeconditions,1,1") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:19] Set("Local/[email protected];2", "TCSTATE=false") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:19] Set("Local/[email protected];2", "TCSTATE=false") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:20] Set("Local/[email protected];2", "TCOVERRIDE=false") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:20] Set("Local/[email protected];2", "TCOVERRIDE=false") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:21] Return("Local/[email protected];2", "") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:21] Return("Local/[email protected];2", "") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:4] System("Local/[email protected];2", "/var/lib/asterisk/bin/schedtc.php 60 /var/spool/asterisk/outgoing 1") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:4] System("Local/[email protected];2", "/var/lib/asterisk/bin/schedtc.php 60 /var/spool/asterisk/outgoing 1") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:5] Answer("Local/[email protected];2", "") in new stack
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: -- Executing [[email protected]:5] Answer("Local/[email protected];2", "") in new stack
[2015-04-28 16:21:00] NOTICE[2697] pbx_spool.c: Call completed to Local/[email protected]
[2015-04-28 16:21:00] NOTICE[2697] pbx_spool.c: Call completed to Local/[email protected]
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: == Spawn extension (tc-maint, s, 5) exited non-zero on 'Local/[email protected];2'
[2015-04-28 16:21:00] VERBOSE[2698] pbx.c: == Spawn extension (tc-maint, s, 5) exited non-zero on 'Local/[email protected];2'

You post a standard timecondition call file , you need to post the logs from BEFORE the call failed (and of course a little after :wink: )

You are also logging everything twice, check your /etc/asterisk/logger*.conf files for the reason.

Sorry! I thought it would contain the issue. Will send again shortly. Regarding the double logging, I can;t find what to do to stop it. I realize there is something about the logger file, but really not sure exactly what to do to stop it. None of the articles i found really gave a step by step…

Only define the full log in one of the logger*.conf files.

Congested may mean that your trunk has more active calls than it is allowed to have.

When the Grandstream sends calls into Asterisk, Asterisk treats them all as coming in on the same trunk, even though you have separate trunks defined for each connection on the Grandstream. Those separate trunks are only used for outbound calls from your PBX -> Grandstream.

In the trunks module, for every Grandstream Trunk, make sure that the maximum channels is 8 or higher, and that may solve your problem.