50% of calls are going on echo test

All extensions are having same problem almost every second call goes to echo test its same echo test that you can access by calling on *43 . every thing was working fine then it starts to appear out on no where and i thought its server fault so i installed brand new freepbx in new server but i am having same problem here . what is it ? i really appreciate is someone can help me on that …

Thankyou.

Provide a call trace of one of these calls:
https://wiki.freepbx.org/display/SUP/Providing+Great+Debug#ProvidingGreatDebug-AsteriskLogs

Make a couple of test calls and post the log snippet of one that does go there.

This sort of scenario usually (in my experience) only happens if you select that destination in one of the applications.
In your call scenario, are the calls going to a queue or ring group? Is it possible someone was messing with their phone and put a call forward as *43?

One possible check is to run this command from the CLI prompt

asterisk -rx "database show" | grep *43

You might see something like :

/CF/9860                                          : *43

That can show potential configurations where the database has it programmed. (this example shows extension 9860 with a Callforward to *43

Its also possible to search the entire SQL database for FreePBX for a possible setting, but see if the above applies first.

1 Like

Sorry but this command is not working in cli or ssh .how do i run this ??

Is it not working, as in giving an error? Or just not returning results.

[root@pbx02 ~]# asterisk -rx "database show" | grep *43
[root@pbx02 ~]#

If you get the above, then it just means that there wasn’t anything in the internal asterisk database that contained that value.

Make a test call and post the log portion of the failed call and we can all take a look.

1 Like

the command mention there tail -f /var/log/asterisk/full giving to much logs to copy and past here… can i do it for like 1 extension and call on it so i can get better details??

yes my results are same as you posted here . and i don’t know how to check for 1 extension only .

fire up the live log

  asterisk -cvvvvvr

make a test call, the log will scroll,

Copy and paste the chunk of log that “moved” (assuming you dont have a whole bunch of other simultaneous calls coming in) and it should show us the exact call.

1 Like

Ok let me make that call and i will post it asap.

I am sorry but too many simultaneously calls are made how can i check for one extension if possible?

well, try this

cat /var/log/asterisk/full | grep *43

I’m going to assume you have a lot of calls doing this, so post the last 30-40 lines

cat /var/log/asterisk/full | grep *43
[2019-03-11 15:56:29] VERBOSE[19968] pbx.c: Added extension ‘*43’ priority 1 to ext-featurecodes
[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 16:13:19] VERBOSE[27959][C-00000db4] pbx.c: Executing [*43@from-internal:1] Set(“SIP/1066-00001b0f”, “CONNECTEDLINE(name-charset,i)=utf8”) in new stack
[2019-03-11 16:13:19] VERBOSE[27959][C-00000db4] pbx.c: Executing [*43@from-internal:2] Set(“SIP/1066-00001b0f”, “CONNECTEDLINE(name,i)=Echo Test”) in new stack
[2019-03-11 16:13:19] VERBOSE[27959][C-00000db4] pbx.c: Executing [*43@from-internal:3] Set(“SIP/1066-00001b0f”, “CONNECTEDLINE(num,i)=*43”) in new stack
[2019-03-11 16:13:19] VERBOSE[27959][C-00000db4] pbx.c: Executing [*43@from-internal:4] Answer(“SIP/1066-00001b0f”, “”) in new stack
[2019-03-11 16:13:19] VERBOSE[27959][C-00000db4] pbx.c: Executing [*43@from-internal:5] Macro(“SIP/1066-00001b0f”, “user-callerid,”) in new stack
[2019-03-11 16:13:19] VERBOSE[27959][C-00000db4] pbx.c: Executing [*43@from-internal:6] Wait(“SIP/1066-00001b0f”, “1”) in new stack
[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:29] VERBOSE[27959][C-00000db4] pbx.c: Spawn extension (from-internal, *43, 7) exited non-zero on ‘SIP/1066-00001b0f’

check extension 1066

Check what in it?? is this the source of problem ? should i delete it?

Well in that log, 1066 SEEMS to be doing something with *43.
Is this in a queue or ring group possibly? If so, perhaps temporarily remove it from the queue (logout or remove from static agents if applicable)

Check UCP (if applicable) to see if the user has done something to their extension?
Look at the physical extension to see if they’ve done something on it. Its possible to press CFWD on the phone and that config not be visible to asterisk.

Right now, extension 1066 (based on log) seems to be the culprit.

Deleted that still facing same issue

run the cat command again.
paste the last 30-40 lines of the log again, see what else shows up.

Also everyone is using soft phone and no one but me is allowed in udp so basically no one got password for it.

cat /var/log/asterisk/full | grep *43
[2019-03-11 15:56:29] VERBOSE[19968] pbx.c: Added extension ‘*43’ priority 1 to ext-featurecodes
[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 16:13:19] VERBOSE[27959][C-00000db4] pbx.c: Executing [*43@from-internal:1] Set(“SIP/1066-00001b0f”, “CONNECTEDLINE(name-charset,i)=utf8”) in new stack
[2019-03-11 16:13:19] VERBOSE[27959][C-00000db4] pbx.c: Executing [*43@from-internal:2] Set(“SIP/1066-00001b0f”, “CONNECTEDLINE(name,i)=Echo Test”) in new stack
[2019-03-11 16:13:19] VERBOSE[27959][C-00000db4] pbx.c: Executing [*43@from-internal:3] Set(“SIP/1066-00001b0f”, “CONNECTEDLINE(num,i)=*43”) in new stack
[2019-03-11 16:13:19] VERBOSE[27959][C-00000db4] pbx.c: Executing [*43@from-internal:4] Answer(“SIP/1066-00001b0f”, “”) in new stack
[2019-03-11 16:13:19] VERBOSE[27959][C-00000db4] pbx.c: Executing [*43@from-internal:5] Macro(“SIP/1066-00001b0f”, “user-callerid,”) in new stack
[2019-03-11 16:13:19] VERBOSE[27959][C-00000db4] pbx.c: Executing [*43@from-internal:6] Wait(“SIP/1066-00001b0f”, “1”) in new stack
[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:29] VERBOSE[27959][C-00000db4] pbx.c: Spawn extension (from-internal, *43, 7) exited non-zero on ‘SIP/1066-00001b0f’
[2019-03-11 17:32:15] VERBOSE[25789] pbx.c: Added extension ‘*43’ priority 1 to ext-featurecodes
[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

Well the last section of log, the times that start with 17:32, that is from a reload (assuming when you removed extension 1066)

Try this for me?

cat /var/log/asterisk/full | grep echo

Maybe its being called in some other manner instead of *43