Follow Me

I am using Free PBX 2.5 and Asterisk 1.4.22 on Trixbox which has been on the machine for a year or more. Yesterday Follow Me stopped working. Extensions with Follow Me set up just go to voice mail after the default ring period. Am tearing my hair out and just can’t track down the problem, is there anything that is mutually exclusive to Follow Me that I might have done to cause this problem, I did quite a bit of setup work yesterday so it is possible.

Follow Me Unavailable works correctly as do Extensions with VMX Locator enabled.

Here is the call flow for extension 120 calling extension 121 which has Follow Me set:

– Executing [121@from-thecable:1] Set(“SIP/120-b7935778”, “__RINGTIMER=10”) in new stack
– Executing [121@from-thecable:2] Macro(“SIP/120-b7935778”, “exten-vm|121|121”) in new stack
– Executing [s@macro-exten-vm:1] Macro(“SIP/120-b7935778”, “user-callerid”) in new stack
– Executing [s@macro-user-callerid:1] Set(“SIP/120-b7935778”, “AMPUSER=120”) in new stack
– Executing [s@macro-user-callerid:2] GotoIf(“SIP/120-b7935778”, “0?report”) in new stack
– Executing [s@macro-user-callerid:3] ExecIf(“SIP/120-b7935778”, “1|Set|REALCALLERIDNUM=120”) in new stack
– Executing [s@macro-user-callerid:4] Set(“SIP/120-b7935778”, “AMPUSER=120”) in new stack
– Executing [s@macro-user-callerid:5] Set(“SIP/120-b7935778”, “AMPUSERCIDNAME=Terry Stone”) in new stack
– Executing [s@macro-user-callerid:6] GotoIf(“SIP/120-b7935778”, “0?report”) in new stack
– Executing [s@macro-user-callerid:7] Set(“SIP/120-b7935778”, “AMPUSERCID=120”) in new stack
– Executing [s@macro-user-callerid:8] Set(“SIP/120-b7935778”, “CALLERID(all)=“Terry Stone” <120>”) in new stack
– Executing [s@macro-user-callerid:9] ExecIf(“SIP/120-b7935778”, “0|Set|CHANNEL(language)=”) in new stack
– Executing [s@macro-user-callerid:10] GotoIf(“SIP/120-b7935778”, “0?continue”) in new stack
– Executing [s@macro-user-callerid:11] Set(“SIP/120-b7935778”, “__TTL=64”) in new stack
– Executing [s@macro-user-callerid:12] GotoIf(“SIP/120-b7935778”, “1?continue”) in new stack
– Goto (macro-user-callerid,s,19)
– Executing [s@macro-user-callerid:19] NoOp(“SIP/120-b7935778”, “Using CallerID “Terry Stone” <120>”) in new stack
– Executing [s@macro-exten-vm:2] Set(“SIP/120-b7935778”, “RingGroupMethod=none”) in new stack
– Executing [s@macro-exten-vm:3] Set(“SIP/120-b7935778”, “VMBOX=121”) in new stack
– Executing [s@macro-exten-vm:4] Set(“SIP/120-b7935778”, “EXTTOCALL=121”) in new stack
– Executing [s@macro-exten-vm:5] Set(“SIP/120-b7935778”, “CFUEXT=”) in new stack
– Executing [s@macro-exten-vm:6] Set(“SIP/120-b7935778”, “CFBEXT=”) in new stack
– Executing [s@macro-exten-vm:7] Set(“SIP/120-b7935778”, “RT=10”) in new stack
– Executing [s@macro-exten-vm:8] Macro(“SIP/120-b7935778”, “record-enable|121|IN”) in new stack
– Executing [s@macro-record-enable:1] GotoIf(“SIP/120-b7935778”, “1?check”) in new stack
– Goto (macro-record-enable,s,4)
– Executing [s@macro-record-enable:4] AGI(“SIP/120-b7935778”, “recordingcheck|20100714-102555|1279117555.493”) in new stack
– Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
recordingcheck|20100714-102555|1279117555.493: Inbound recording not enabled
– AGI Script recordingcheck completed, returning 0
– Executing [s@macro-record-enable:5] MacroExit(“SIP/120-b7935778”, “”) in new stack
– Executing [s@macro-exten-vm:9] Macro(“SIP/120-b7935778”, “dial|10|tr|121”) in new stack
– Executing [s@macro-dial:1] GotoIf(“SIP/120-b7935778”, “1?dial”) in new stack
– Goto (macro-dial,s,3)
– Executing [s@macro-dial:3] AGI(“SIP/120-b7935778”, “dialparties.agi”) in new stack
– Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
dialparties.agi: Starting New Dialparties.agi
== Parsing ‘/etc/asterisk/manager.conf’: Found
== Parsing ‘/etc/asterisk/manager_additional.conf’: Found
== Parsing ‘/etc/asterisk/manager_custom.conf’: Found
== Manager ‘admin’ logged on from 127.0.0.1
dialparties.agi: Caller ID name is ‘Terry Stone’ number is '120’
dialparties.agi: Methodology of ring is ‘none’
– dialparties.agi: Added extension 121 to extension map
– dialparties.agi: Extension 121 cf is disabled
– dialparties.agi: Extension 121 do not disturb is disabled
dialparties.agi: ExtensionState: 0
– dialparties.agi: dbset CALLTRACE/121 to 120
– dialparties.agi: Filtered ARG3: 121
== Manager ‘admin’ logged off from 127.0.0.1
– AGI Script dialparties.agi completed, returning 0
– Executing [s@macro-dial:7] Dial(“SIP/120-b7935778”, “SIP/121|10|tr”) in new stack
– Called 121
– SIP/121-09e5f7a0 is ringing
– Nobody picked up in 10000 ms
– Executing [s@macro-dial:8] Set(“SIP/120-b7935778”, “DIALSTATUS=NOANSWER”) in new stack
– Executing [s@macro-dial:9] GosubIf(“SIP/120-b7935778”, “0?NOANSWER|1”) in new stack
– Executing [s@macro-exten-vm:10] GotoIf(“SIP/120-b7935778”, “0?exit|return”) in new stack
– Executing [s@macro-exten-vm:11] Set(“SIP/120-b7935778”, “SV_DIALSTATUS=NOANSWER”) in new stack
– Executing [s@macro-exten-vm:12] GosubIf(“SIP/120-b7935778”, “0?docfu|1”) in new stack
– Executing [s@macro-exten-vm:13] GosubIf(“SIP/120-b7935778”, “0?docfb|1”) in new stack
– Executing [s@macro-exten-vm:14] Set(“SIP/120-b7935778”, “DIALSTATUS=NOANSWER”) in new stack
– Executing [s@macro-exten-vm:15] NoOp(“SIP/120-b7935778”, “Voicemail is 121”) in new stack
– Executing [s@macro-exten-vm:16] GotoIf(“SIP/120-b7935778”, “0?s-NOANSWER|1”) in new stack
– Executing [s@macro-exten-vm:17] NoOp(“SIP/120-b7935778”, “Sending to Voicemail box 121”) in new stack
– Executing [s@macro-exten-vm:18] Macro(“SIP/120-b7935778”, “vm|121|NOANSWER|”) in new stack
– Executing [s@macro-vm:1] Macro(“SIP/120-b7935778”, “user-callerid|SKIPTTL”) in new stack
– Executing [s@macro-user-callerid:1] Set(“SIP/120-b7935778”, “AMPUSER=120”) in new stack
– Executing [s@macro-user-callerid:2] GotoIf(“SIP/120-b7935778”, “0?report”) in new stack
– Executing [s@macro-user-callerid:3] ExecIf(“SIP/120-b7935778”, “0|Set|REALCALLERIDNUM=120”) in new stack
– Executing [s@macro-user-callerid:4] Set(“SIP/120-b7935778”, “AMPUSER=120”) in new stack
– Executing [s@macro-user-callerid:5] Set(“SIP/120-b7935778”, “AMPUSERCIDNAME=Terry Stone”) in new stack
– Executing [s@macro-user-callerid:6] GotoIf(“SIP/120-b7935778”, “0?report”) in new stack
– Executing [s@macro-user-callerid:7] Set(“SIP/120-b7935778”, “AMPUSERCID=120”) in new stack
– Executing [s@macro-user-callerid:8] Set(“SIP/120-b7935778”, “CALLERID(all)=“Terry Stone” <120>”) in new stack
– Executing [s@macro-user-callerid:9] ExecIf(“SIP/120-b7935778”, “0|Set|CHANNEL(language)=”) in new stack
– Executing [s@macro-user-callerid:10] GotoIf(“SIP/120-b7935778”, “1?continue”) in new stack
– Goto (macro-user-callerid,s,19)
– Executing [s@macro-user-callerid:19] NoOp(“SIP/120-b7935778”, “Using CallerID “Terry Stone” <120>”) in new stack
– Executing [s@macro-vm:2] Set(“SIP/120-b7935778”, “VMGAIN=”"") in new stack
– Executing [s@macro-vm:3] GotoIf(“SIP/120-b7935778”, “1?vmx|1”) in new stack
– Goto (macro-vm,vmx,1)
– Executing [vmx@macro-vm:1] GotoIf(“SIP/120-b7935778”, “0?s-NOANSWER|1”) in new stack
– Executing [vmx@macro-vm:2] Set(“SIP/120-b7935778”, “MODE=unavail”) in new stack
– Executing [vmx@macro-vm:3] GotoIf(“SIP/120-b7935778”, “1?notdirect”) in new stack
– Goto (macro-vm,vmx,5)
– Executing [vmx@macro-vm:5] NoOp(“SIP/120-b7935778”, "Checking if ext 121 is enabled: ") in new stack
– Executing [vmx@macro-vm:6] GotoIf(“SIP/120-b7935778”, “1?s-NOANSWER|1”) in new stack
– Goto (macro-vm,s-NOANSWER,1)
– Executing [s-NOANSWER@macro-vm:1] Macro(“SIP/120-b7935778”, “get-vmcontext|121”) in new stack
– Executing [s@macro-get-vmcontext:1] Set(“SIP/120-b7935778”, “VMCONTEXT=default”) in new stack
– Executing [s@macro-get-vmcontext:2] GotoIf(“SIP/120-b7935778”, “0?200:300”) in new stack
– Goto (macro-get-vmcontext,s,300)
– Executing [s@macro-get-vmcontext:300] NoOp(“SIP/120-b7935778”, “”) in new stack
– Executing [s-NOANSWER@macro-vm:2] VoiceMail(“SIP/120-b7935778”, “121@default|u”) in new stack
– <SIP/120-b7935778> Playing ‘vm-theperson’ (language ‘en’)
– <SIP/120-b7935778> Playing ‘digits/1’ (language ‘en’)
– <SIP/120-b7935778> Playing ‘digits/2’ (language ‘en’)
– <SIP/120-b7935778> Playing ‘digits/1’ (language ‘en’)
– <SIP/120-b7935778> Playing ‘vm-isunavail’ (language ‘en’)
– <SIP/120-b7935778> Playing ‘vm-intro’ (language ‘en’)
== Spawn extension (macro-vm, s-NOANSWER, 2) exited non-zero on ‘SIP/120-b7935778’ in macro ‘vm’
== Spawn extension (macro-vm, s-NOANSWER, 2) exited non-zero on ‘SIP/120-b7935778’ in macro ‘exten-vm’
== Spawn extension (macro-vm, s-NOANSWER, 2) exited non-zero on ‘SIP/120-b7935778’

that example is not going to follow-me, it is just calling the extension.

Phillipe I agree, but the question is why, Follow Me is as far as I can see set up correctly. I have looked at the code but I have not been able to work out where the test for Follow Me is done, could you give me some insight please?

are you using custom_context by any chance?

Yes, quite extensively.

Phillipe,

I have come to a dead end trying to work this one out, any ideas on possible causes?

Thanks in advance.

you probably have ext-local higher up (lower priority) then ext-findmefollow, so your follow-me is never being hit.

External calls coming in work fine because they use a context that specifically orders those two properly.

Thanks Phillipe,

Both had the same priority (50) so in one custom context I gave ext-findmefollow a higher priority (49) and the problem went away. The strange thing is that it now works fine in other custom contexts where both have the same priority (50) whereas it did not before I made the change. Any thoughts on this?

I also notice if the follow me goes to a trunk it is not the trunk allowed in the custom context for the extension but the trunk that would have been selected if the allow all (default) context were used. Would this be the expected behavior?

if you don’t set a priority then I believe it is going to be un-deterministic. You would have to look at the order by key in the sql query but expect priority is the only thing that will guarantee an order and is why they put that in there.

custom-context has limitations and one of those is using things like follow-me, call forwarding, etc. In those cases, the call ends up back in from-internal. That is a ‘security’ limitation of custom-context and one of the reasons why it is only available from the Extended Repository. Fixing that requires making quite a few changes to core (not something that can be controlled by the custom context module alone).