Inbound routing big error or big mistake?

jochenthomas · May 20, 2009, 2:20pm

Hi,
I believe FreePBX 2.5.1 (or PiaF) has a big error in the inbound routing!!

I installed a new system (second time); Asterisk 1.4 with IAX2 trunk.
There is no phone connected (only an IAX-device during tests).

I created an extension with the number 0049123456789 and a “follow me” to a mobile (special outbound route).
If I ring this number internally from the IAX-device all works as expected (no sip-phone connected! >> follow me to external >> oubound route >> the mobile is ringing).

BUT!! a ring from outside produces a completely different picture: they will get immediately the message “.ext. 0049123456789 is not available please leave a message” (if VM is activated).

And also disturbing:

Later I created an inbound route (0049987654321) and directed it to the phone directory (which means a clear and very, very simple routing!!). But in this case the routing dosn’t work (number not available), see following:

[2009-05-20 15:01:01] NOTICE[3090] chan_iax2.c: Rejected connect attempt from 217.xxx.xxx.xx, request ‘0049123456789@default’ does not exist

If I create an extension with a two digit number and then direct an inbound route to it the same result appears: the caller gets a carrier-network message that the number is currently not available.

If the IAX device is connected I can ring that extension (0049123456788) and the iax-device rings. If I create an inbound route it dosn’t work.

What the hell is that?
I had never before such problems, used the same trunk parameters and the same or similar routing (at least 2-5 years).

Can anybody help? Thanks in advance

Is there a precondition which has to be fullfilled from the carrier?
What I have to consider?
Should I use two digit extension and use the inbound route (which would be automatically created) OR should I use the long 0049123456789-extension (which dosn’t need a special inbound routing)?

If it is necessary to test a special configuration I will post the trace - please let me know.

Many thanks for any advice.

SkykingOH · May 20, 2009, 3:05pm

This certainly works, no issue so it is something on your end.

Sounds to me as if you are calling from your cell phone to test. Since it forwards back to your cell phone the carriers network ‘sees’ you as yourself and dumps to the voicemail box.

If this is not the case call traces would help us diagnose.

jochenthomas · May 21, 2009, 8:06pm

No, no…
called from Mobile but as well from Landline…
But in both situations the same result.

And also I can see a second call is comming in, which worked in a previous version perfectely

So this is not the stumbling block.

Greetings, an thanks for your answer.

fskrotzki · May 22, 2009, 12:58pm

As SkykingOH said in his last statement. “call traces would help us”. So please set the verbose level to at least 3 if not 5, start capturing the data and make the call attempt. Once you have the call tract post it here for us to review otherwise we are just guessing and shooting in the dark while attempting to help you.

jochenthomas · May 25, 2009, 4:07pm

Hi,
sorry for the delay, some public holidays in Germany

Below you can find a trace which I hope will help you.

I created an extension 0049________11 which got an external call (0049_CALLER____).
The phone was NOT connected!

Follow me was enabled in this way:
(VmX Locator: Disabled)
(no special inbound route created)

Initial ring time: 1
ring strategy: ringallv2-prim
ring time : 60
Follow me list: 0049________11 and 99110049________78 (via outbound route)
Play music on hold xxxx
Destination if no answer: Terminate Call: Hangup !!!

After ringing the voicebox automatically appears an no Hangup!!

Hope this trace can help, if not I can create another one, please let me know in which kind of call routing.

Best regards
Jochen

Trace:

[2009-05-25 17:43:29] VERBOSE[3088] logger.c: – Accepting AUTHENTICATED call from 217.74.xxx.xxx:

requested format = alaw,

requested prefs = (alaw|g729|gsm),

actual format = alaw,

host prefs = (alaw|g729|gsm),

priority = mine

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [0049________11@default:1] Macro(“IAX2/bs_out_25-3033”, “exten-vm|0049________11|0049________11”) in new stack

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-exten-vm:1] Macro(“IAX2/bs_out_25-3033”, “user-callerid”) in new stack

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-user-callerid:1] Set(“IAX2/bs_out_25-3033”, “AMPUSER=0049_CALLER____”) in new stack

[2009-05-25 17:43:29] DEBUG[19830] app_macro.c: Executed application: Set

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-user-callerid:2] GotoIf(“IAX2/bs_out_25-3033”, “0?report”) in new stack

[2009-05-25 17:43:29] DEBUG[19830] app_macro.c: Executed application: GotoIf

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-user-callerid:3] ExecIf(“IAX2/bs_out_25-3033”, “1|Set|REALCALLERIDNUM=0049_CALLER____”) in new stack

[2009-05-25 17:43:29] DEBUG[19830] app_macro.c: Executed application: ExecIf

[2009-05-25 17:43:29] DEBUG[19830] func_db.c: DB: DEVICE/0049_CALLER____/user not found in database.

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-user-callerid:4] Set(“IAX2/bs_out_25-3033”, “AMPUSER=”) in new stack

[2009-05-25 17:43:29] DEBUG[19830] app_macro.c: Executed application: Set

[2009-05-25 17:43:29] DEBUG[19830] func_db.c: DB: AMPUSER//cidname not found in database.

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-user-callerid:5] Set(“IAX2/bs_out_25-3033”, “AMPUSERCIDNAME=”) in new stack

[2009-05-25 17:43:29] DEBUG[19830] app_macro.c: Executed application: Set

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-user-callerid:6] GotoIf(“IAX2/bs_out_25-3033”, “1?report”) in new stack

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Goto (macro-user-callerid,s,11)

[2009-05-25 17:43:29] DEBUG[19830] app_macro.c: Executed application: GotoIf

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-user-callerid:11] GotoIf(“IAX2/bs_out_25-3033”, “0?continue”) in new stack

[2009-05-25 17:43:29] DEBUG[19830] app_macro.c: Executed application: GotoIf

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-user-callerid:12] Set(“IAX2/bs_out_25-3033”, “__TTL=64”) in new stack

[2009-05-25 17:43:29] DEBUG[19830] app_macro.c: Executed application: Set

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-user-callerid:13] GotoIf(“IAX2/bs_out_25-3033”, “1?continue”) in new stack

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Goto (macro-user-callerid,s,20)

[2009-05-25 17:43:29] DEBUG[19830] app_macro.c: Executed application: GotoIf

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-user-callerid:20] NoOp(“IAX2/bs_out_25-3033”, “Using CallerID “” <0049_CALLER____>”) in new stack

[2009-05-25 17:43:29] DEBUG[19830] app_macro.c: Executed application: Noop

[2009-05-25 17:43:29] DEBUG[19830] app_macro.c: Executed application: Macro

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-exten-vm:2] Set(“IAX2/bs_out_25-3033”, “RingGroupMethod=none”) in new stack

[2009-05-25 17:43:29] DEBUG[19830] app_macro.c: Executed application: Set

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-exten-vm:3] Set(“IAX2/bs_out_25-3033”, “VMBOX=0049________11”) in new stack

[2009-05-25 17:43:29] DEBUG[19830] app_macro.c: Executed application: Set

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-exten-vm:4] Set(“IAX2/bs_out_25-3033”, “EXTTOCALL=0049________11”) in new stack

[2009-05-25 17:43:29] DEBUG[19830] app_macro.c: Executed application: Set

[2009-05-25 17:43:29] DEBUG[19830] func_db.c: DB: CFU/0049________11 not found in database.

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-exten-vm:5] Set(“IAX2/bs_out_25-3033”, “CFUEXT=”) in new stack

[2009-05-25 17:43:29] DEBUG[19830] app_macro.c: Executed application: Set

[2009-05-25 17:43:29] DEBUG[19830] func_db.c: DB: CFB/0049________11 not found in database.

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-exten-vm:6] Set(“IAX2/bs_out_25-3033”, “CFBEXT=”) in new stack

[2009-05-25 17:43:29] DEBUG[19830] app_macro.c: Executed application: Set

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-exten-vm:7] Set(“IAX2/bs_out_25-3033”, “RT=45”) in new stack

[2009-05-25 17:43:29] DEBUG[19830] app_macro.c: Executed application: Set

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-exten-vm:8] Macro(“IAX2/bs_out_25-3033”, “record-enable|0049________11|IN”) in new stack

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-record-enable:1] GotoIf(“IAX2/bs_out_25-3033”, “1?check”) in new stack

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Goto (macro-record-enable,s,4)

[2009-05-25 17:43:29] DEBUG[19830] app_macro.c: Executed application: GotoIf

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-record-enable:4] AGI(“IAX2/bs_out_25-3033”, “recordingcheck|20090525-174329|1243266209.277”) in new stack

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: recordingcheck|20090525-174329|1243266209.277: Inbound recording enabled.

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: recordingcheck|20090525-174329|1243266209.277: CALLFILENAME=20090525-174329-1243266209.277

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – AGI Script recordingcheck completed, returning 0

[2009-05-25 17:43:29] DEBUG[19830] app_macro.c: Executed application: AGI

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-record-enable:999] MixMonitor(“IAX2/bs_out_25-3033”, “20090525-174329-1243266209.277.wav||”) in new stack

[2009-05-25 17:43:29] DEBUG[19830] app_macro.c: Executed application: MixMonitor

[2009-05-25 17:43:29] DEBUG[19830] app_macro.c: Executed application: Macro

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-exten-vm:9] Macro(“IAX2/bs_out_25-3033”, “dial|45|tr|0049________11”) in new stack

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-dial:1] GotoIf(“IAX2/bs_out_25-3033”, “1?dial”) in new stack

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Goto (macro-dial,s,3)

[2009-05-25 17:43:29] DEBUG[19830] app_macro.c: Executed application: GotoIf

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-dial:3] AGI(“IAX2/bs_out_25-3033”, “dialparties.agi”) in new stack

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi

[2009-05-25 17:43:29] VERBOSE[19832] logger.c: == Begin MixMonitor Recording IAX2/bs_out_25-3033

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: dialparties.agi: Starting New Dialparties.agi

[2009-05-25 17:43:29] VERBOSE[19834] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [2009-05-25 17:43:29] VERBOSE[19834] logger.c: Found

[2009-05-25 17:43:29] VERBOSE[19834] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [2009-05-25 17:43:29] VERBOSE[19834] logger.c: Found

[2009-05-25 17:43:29] VERBOSE[19834] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [2009-05-25 17:43:29] VERBOSE[19834] logger.c: Found

[2009-05-25 17:43:29] VERBOSE[19834] logger.c: == Manager ‘admin’ logged on from 127.0.0.1

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: dialparties.agi: Caller ID name is ‘unknown’ number is ‘0049_CALLER____’

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: dialparties.agi: Methodology of ring is ‘none’

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – dialparties.agi: Added extension 0049________11 to extension map

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – dialparties.agi: Extension 0049________11 cf is disabled

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – dialparties.agi: Extension 0049________11 do not disturb is disabled

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: dialparties.agi: Extension 0049________11 has ExtensionState: 4

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – dialparties.agi: Checking CW and CFB status for extension 0049________11

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – dialparties.agi: dbset CALLTRACE/0049________11 to 0049_CALLER____

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – dialparties.agi: Filtered ARG3: 0049________11

[2009-05-25 17:43:29] VERBOSE[19834] logger.c: == Manager ‘admin’ logged off from 127.0.0.1

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – AGI Script dialparties.agi completed, returning 0

[2009-05-25 17:43:29] DEBUG[19830] app_macro.c: Executed application: AGI

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-dial:7] Dial(“IAX2/bs_out_25-3033”, “SIP/0049________11|45|tr”) in new stack

[2009-05-25 17:43:29] WARNING[19830] app_dial.c: Unable to create channel of type ‘SIP’ (cause 3 - No route to destination)

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: == Everyone is busy/congested at this time (1:0/0/1)

[2009-05-25 17:43:29] DEBUG[19830] app_macro.c: Executed application: Dial

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-dial:8] Set(“IAX2/bs_out_25-3033”, “DIALSTATUS=CHANUNAVAIL”) in new stack

[2009-05-25 17:43:29] DEBUG[19830] app_macro.c: Executed application: Set

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-dial:9] GosubIf(“IAX2/bs_out_25-3033”, “0?CHANUNAVAIL|1”) in new stack

[2009-05-25 17:43:29] DEBUG[19830] app_macro.c: Executed application: GosubIf

[2009-05-25 17:43:29] DEBUG[19830] app_macro.c: Executed application: Macro

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-exten-vm:10] GotoIf(“IAX2/bs_out_25-3033”, “0?exit|return”) in new stack

[2009-05-25 17:43:29] DEBUG[19830] app_macro.c: Executed application: GotoIf

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-exten-vm:11] Set(“IAX2/bs_out_25-3033”, “SV_DIALSTATUS=CHANUNAVAIL”) in new stack

[2009-05-25 17:43:29] DEBUG[19830] app_macro.c: Executed application: Set

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-exten-vm:12] GosubIf(“IAX2/bs_out_25-3033”, “0?docfu|1”) in new stack

[2009-05-25 17:43:29] DEBUG[19830] app_macro.c: Executed application: GosubIf

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-exten-vm:13] GosubIf(“IAX2/bs_out_25-3033”, “0?docfb|1”) in new stack

[2009-05-25 17:43:29] DEBUG[19830] app_macro.c: Executed application: GosubIf

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-exten-vm:14] Set(“IAX2/bs_out_25-3033”, “DIALSTATUS=CHANUNAVAIL”) in new stack

[2009-05-25 17:43:29] DEBUG[19830] app_macro.c: Executed application: Set

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-exten-vm:15] NoOp(“IAX2/bs_out_25-3033”, “Voicemail is 0049________11”) in new stack

[2009-05-25 17:43:29] DEBUG[19830] app_macro.c: Executed application: NoOp

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-exten-vm:16] GotoIf(“IAX2/bs_out_25-3033”, “0?s-CHANUNAVAIL|1”) in new stack

[2009-05-25 17:43:29] DEBUG[19830] app_macro.c: Executed application: GotoIf

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-exten-vm:17] NoOp(“IAX2/bs_out_25-3033”, “Sending to Voicemail box 0049________11”) in new stack

[2009-05-25 17:43:29] DEBUG[19830] app_macro.c: Executed application: NoOp

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-exten-vm:18] Macro(“IAX2/bs_out_25-3033”, “vm|0049________11|CHANUNAVAIL|”) in new stack

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-vm:1] Macro(“IAX2/bs_out_25-3033”, “user-callerid|SKIPTTL”) in new stack

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-user-callerid:1] Set(“IAX2/bs_out_25-3033”, “AMPUSER=0049_CALLER____”) in new stack

[2009-05-25 17:43:29] DEBUG[19830] app_macro.c: Executed application: Set

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-user-callerid:2] GotoIf(“IAX2/bs_out_25-3033”, “0?report”) in new stack

[2009-05-25 17:43:29] DEBUG[19830] app_macro.c: Executed application: GotoIf

[2009-05-25 17:43:29] VERBOSE[19830] logger.c: – Executing [s@macro-user-callerid:3] ExecIf(“IAX2/bs_out_25-3033”, “0|Set|REALCALLERIDNUM=0049_CALLER____”) in new stack