50% of calls are going on echo test

You guys are just going in circles, as requested already by Lorne, please post a full call log.

Use pastebin as outlined here https://wiki.freepbx.org/display/SUP/Providing+Great+Debug#ProvidingGreatDebug-AsteriskLogs-PartII

cat /var/log/asterisk/full | grep echo
[2019-03-11 15:56:29] VERBOSE[19968] pbx.c: Registered extension context ‘app-echo-test’; registrar: pbx_config
[2019-03-11 15:56:29] VERBOSE[19968] pbx.c: Including context ‘app-echo-test-custom’ in context ‘app-echo-test’
[2019-03-11 15:56:29] VERBOSE[19968] pbx.c: Added extension ‘*43’ priority 1 to app-echo-test
[2019-03-11 15:56:29] VERBOSE[19968] pbx.c: Added extension ‘*43’ priority 2 to app-echo-test
[2019-03-11 15:56:29] VERBOSE[19968] pbx.c: Added extension ‘*43’ priority 3 to app-echo-test
[2019-03-11 15:56:29] VERBOSE[19968] pbx.c: Added extension ‘*43’ priority 4 to app-echo-test
[2019-03-11 15:56:29] VERBOSE[19968] pbx.c: Added extension ‘*43’ priority 5 to app-echo-test
[2019-03-11 15:56:29] VERBOSE[19968] pbx.c: Added extension ‘43’ priority 6 to app-echo-test
[2019-03-11 15:56:29] VERBOSE[19968] pbx.c: Added extension ‘43’ priority 7 to app-echo-test
[2019-03-11 15:56:29] VERBOSE[19968] pbx.c: Added extension ‘43’ priority 8 to app-echo-test
[2019-03-11 15:56:29] VERBOSE[19968] pbx.c: Registered extension context ‘app-echo-test-echo’; registrar: pbx_config
[2019-03-11 15:56:29] VERBOSE[19968] pbx.c: Including context ‘app-echo-test-echo-custom’ in context ‘app-echo-test-echo’
[2019-03-11 15:56:29] VERBOSE[19968] pbx.c: Added extension '_[0-9#
]’ priority 1 to app-echo-test-echo
[2019-03-11 15:56:29] VERBOSE[19968] pbx.c: Added extension '_[0-9#
]’ priority 2 to app-echo-test-echo
[2019-03-11 15:56:29] VERBOSE[19968] pbx.c: Added extension '_[0-9#
]’ priority 3 to app-echo-test-echo
[2019-03-11 16:13:20] VERBOSE[27959][C-00000db4] pbx.c: Executing [*43@from-internal:7] BackGround(“SIP/1066-00001b0f”, “demo-echotest,app-echo-test-echo”) in new stack
[2019-03-11 16:13:20] VERBOSE[27959][C-00000db4] file.c: <SIP/1066-00001b0f> Playing ‘demo-echotest.ulaw’ (language ‘en’)
[2019-03-11 17:32:15] VERBOSE[25789] pbx.c: Registered extension context ‘app-echo-test’; registrar: pbx_config
[2019-03-11 17:32:15] VERBOSE[25789] pbx.c: Including context ‘app-echo-test-custom’ in context ‘app-echo-test’
[2019-03-11 17:32:15] VERBOSE[25789] pbx.c: Added extension ‘*43’ priority 1 to app-echo-test
[2019-03-11 17:32:15] VERBOSE[25789] pbx.c: Added extension ‘*43’ priority 2 to app-echo-test
[2019-03-11 17:32:15] VERBOSE[25789] pbx.c: Added extension ‘*43’ priority 3 to app-echo-test
[2019-03-11 17:32:15] VERBOSE[25789] pbx.c: Added extension ‘*43’ priority 4 to app-echo-test
[2019-03-11 17:32:15] VERBOSE[25789] pbx.c: Added extension ‘*43’ priority 5 to app-echo-test
[2019-03-11 17:32:15] VERBOSE[25789] pbx.c: Added extension ‘43’ priority 6 to app-echo-test
[2019-03-11 17:32:15] VERBOSE[25789] pbx.c: Added extension ‘43’ priority 7 to app-echo-test
[2019-03-11 17:32:15] VERBOSE[25789] pbx.c: Added extension ‘43’ priority 8 to app-echo-test
[2019-03-11 17:32:15] VERBOSE[25789] pbx.c: Registered extension context ‘app-echo-test-echo’; registrar: pbx_config
[2019-03-11 17:32:15] VERBOSE[25789] pbx.c: Including context ‘app-echo-test-echo-custom’ in context ‘app-echo-test-echo’
[2019-03-11 17:32:15] VERBOSE[25789] pbx.c: Added extension '_[0-9#
]’ priority 1 to app-echo-test-echo
[2019-03-11 17:32:15] VERBOSE[25789] pbx.c: Added extension '_[0-9#
]’ priority 2 to app-echo-test-echo
[2019-03-11 17:32:15] VERBOSE[25789] pbx.c: Added extension '_[0-9#
]’ priority 3 to app-echo-test-echo
[2019-03-11 17:32:15] VERBOSE[25789] pbx.c: Including context ‘app-echo-test’ in context ‘from-internal-additional’
[2019-03-11 17:32:15] WARNING[25789] pbx.c: Context ‘app-echo-test-echo’ tries to include nonexistent context ‘app-echo-test-echo-custom’
[2019-03-11 17:32:15] WARNING[25789] pbx.c: Context ‘app-echo-test’ tries to include nonexistent context ‘app-echo-test-custom’

Seems pretty normal. I don’t suppose you have a provider or another PBX that is handling your trunks that could be playing the message?

One of calls has this problem so i used its unique id for logs hope its helpful.

grep 1552307650.11485 /var/log/asterisk/full*

/var/log/asterisk/full:[2019-03-11 17:34:10] VERBOSE[26347][C-000016c2] pbx.c: E xecuting [s@macro-user-callerid:1] Set(“SIP/1001-00002cdd”, “TOUCH_MONITOR=15523 07650.11485”) in new stack
/var/log/asterisk/full:[2019-03-11 17:34:10] VERBOSE[26347][C-000016c2] pbx.c: E xecuting [recordcheck@sub-record-check:17] Set(“SIP/1001-00002cdd”, “__CALLFILEN AME=out-********-1001-20190311-173410-1552307650.11485”) in new stack
/var/log/asterisk/full:[2019-03-11 17:34:10] VERBOSE[26347][C-000016c2] pbx.c: E xecuting [recordcheck@sub-record-check:18] MixMonitor(“SIP/1001-00002cdd”, “2019 /03/11/out--1001-20190311-173410-1552307650.11485.wav,abi(LOCAL_MIXM ON_ID),") in new stack
/var/log/asterisk/full:[2019-03-11 17:34:10] VERBOSE[26347][C-000016c2] pbx.c: E xecuting [recordcheck@sub-record-check:22] Set(“SIP/1001-00002cdd”, "CDR(recordi ngfile)=out-
-1001-20190311-173410-1552307650.11485.wav”) in new stac k
/var/log/asterisk/full:[2019-03-11 17:34:17] VERBOSE[26347][C-000016c2] pbx.c: E xecuting [s@crm-hangup:4] NoOp(“SIP/1001-00002cdd”, “MASTER CHANNEL: 1552307650. 11485 = 1552307650.11485”) in new stack

no we have 1 provider and 2 servers .1 is freepbx and another is something else .only freepbx calls get this error other server is working fine.

Please follow the instructions from the link.

grep C-000016c2 /var/log/asterisk/full | pastebin

https://pastebin.freepbx.org/view/b16abeb9

From your pastebin we can see an outbound call, progresses thru normal call flow resulting in normal trunk call:

[2019-03-11 17:34:10] VERBOSE[26347][C-000016c2] app_dial.c: Called SIP/bake/441608684835
[2019-03-11 17:34:11] VERBOSE[26347][C-000016c2] app_dial.c: SIP/bake-00002cde is making progress passing it to SIP/1001-00002cdd
[2019-03-11 17:34:12] VERBOSE[26347][C-000016c2] app_dial.c: SIP/bake-00002cde answered SIP/1001-00002cdd

After 5 seconds the call hung up. You are looking in the wrong place for the problem.

I made ~6 calls to the number and got the IVR each time “press 1 to get the shop …” If the caller hears the echo test after selecting an option, please provide details. Otherwise, it may be dependent on the incoming caller ID or carrier.

no its directly echo test i tried my self and check recordings … its as soon as call connect it starts

yes if you try several time you get call connected but some time its echo test

so where am i suppose to look at??? i am new to all these .

Tried 10 times more and got IVR each time.

yes I got IVR too but problem is why freepbx giving echo test instead to ivr???

There’s zero information in the logs that the call went to echo test.

Find a call in CDR which you are positive that it had this echo issue and post the log file.

yes i am doing that atm

So this problem is not happening on inbound calls, its only happening on outbound calls!
Check your outbound route failover destination. “Optional Destination on Congestion” the default is usually “Normal Congestion”. As a test, set it to “TERMINATE CALL -> HANGUP”

Since its outbound, and its happening for everyone, then this is probably the most likely reason.
It could also be a downstream PBX, maybe your provider. Have you asked them?

setting applied … waiting for if problem appear again and provider said we dont have any thing like that…

As mentioned by @PitzKey, pull up a CDR file of a call that fails
Then click on the callid# under the “SYSTEM” column. That will give you details of the exact call.


Thats all there is now it shows nothing but its same call with problem.