Extension to Extension calling not working

I am running FreePBX 2.10.1.1. I have extensions set up in three digit format (201, 201, etc.). I don’t know how long this has been going on but I can no longer call from one extension to the next. I get a fast busy signal. A log of a call is below - it ends with:

[2012-07-03 20:32:05] WARNING[2436] pbx.c: Channel ‘SIP/201-085ae7b8’ sent into invalid extension ‘novm’ in context ‘sub-record-check’, but no invalid handler

I also noticed I am getting the following error message recently:

[2012-07-03 20:32:10] WARNING[2438] manager.c: Invalid write timeout value ‘’ at line 10

Thanks for any help.

[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [[email protected]:1] Set(“SIP/201-085ae7b8”, “__RINGTIMER=8”) in new stack
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [[email protected]:2] Macro(“SIP/201-085ae7b8”, “exten-vm|novm|201|0|0|0”) in new stack
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [[email protected]:1] Macro(“SIP/201-085ae7b8”, “user-callerid|”) in new stack
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [[email protected]:1] Set(“SIP/201-085ae7b8”, “AMPUSER=201”) in new stack
[2012-07-03 20:32:05] DEBUG[2436] app_macro.c: Executed application: Set
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [[email protected]:2] GotoIf(“SIP/201-085ae7b8”, “0?report”) in new stack
[2012-07-03 20:32:05] DEBUG[2436] app_macro.c: Executed application: GotoIf
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [[email protected]:3] ExecIf(“SIP/201-085ae7b8”, “1|Set|REALCALLERIDNUM=201”) in new stack
[2012-07-03 20:32:05] DEBUG[2436] app_macro.c: Executed application: ExecIf
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [[email protected]:4] Set(“SIP/201-085ae7b8”, “AMPUSER=201”) in new stack
[2012-07-03 20:32:05] DEBUG[2436] app_macro.c: Executed application: Set
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [[email protected]:5] Set(“SIP/201-085ae7b8”, “AMPUSERCIDNAME=Mud Room”) in new stack
[2012-07-03 20:32:05] DEBUG[2436] app_macro.c: Executed application: Set
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [[email protected]:6] GotoIf(“SIP/201-085ae7b8”, “0?report”) in new stack
[2012-07-03 20:32:05] DEBUG[2436] app_macro.c: Executed application: GotoIf
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [[email protected]:7] Set(“SIP/201-085ae7b8”, “AMPUSERCID=201”) in new stack
[2012-07-03 20:32:05] DEBUG[2436] app_macro.c: Executed application: Set
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [[email protected]:8] Set(“SIP/201-085ae7b8”, “CALLERID(all)=“Mud Room” <201>”) in new stack
[2012-07-03 20:32:05] DEBUG[2436] app_macro.c: Executed application: Set
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [[email protected]:9] GotoIf(“SIP/201-085ae7b8”, “0?limit”) in new stack
[2012-07-03 20:32:05] DEBUG[2436] app_macro.c: Executed application: GotoIf
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [[email protected]:10] ExecIf(“SIP/201-085ae7b8”, “0|Set|GROUP(concurrency_limit)=201”) in new stack
[2012-07-03 20:32:05] DEBUG[2436] app_macro.c: Executed application: ExecIf
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [[email protected]:11] ExecIf(“SIP/201-085ae7b8”, “0|Set|CHANNEL(language)=”) in new stack
[2012-07-03 20:32:05] DEBUG[2436] app_macro.c: Executed application: ExecIf
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [[email protected]:12] GotoIf(“SIP/201-085ae7b8”, “0?continue”) in new stack
[2012-07-03 20:32:05] DEBUG[2436] app_macro.c: Executed application: GotoIf
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [[email protected]:13] Set(“SIP/201-085ae7b8”, “__TTL=64”) in new stack
[2012-07-03 20:32:05] DEBUG[2436] app_macro.c: Executed application: Set
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [[email protected]:14] GotoIf(“SIP/201-085ae7b8”, “1?continue”) in new stack
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Goto (macro-user-callerid,s,25)
[2012-07-03 20:32:05] DEBUG[2436] app_macro.c: Executed application: GotoIf
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [[email protected]:25] Set(“SIP/201-085ae7b8”, “CALLERID(number)=201”) in new stack
[2012-07-03 20:32:05] DEBUG[2436] app_macro.c: Executed application: Set
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [[email protected]:26] Set(“SIP/201-085ae7b8”, “CALLERID(name)=Mud Room”) in new stack
[2012-07-03 20:32:05] DEBUG[2436] app_macro.c: Executed application: Set
[2012-07-03 20:32:05] DEBUG[2436] app_macro.c: Executed application: Macro
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [[email protected]:2] Set(“SIP/201-085ae7b8”, “RingGroupMethod=none”) in new stack
[2012-07-03 20:32:05] DEBUG[2436] app_macro.c: Executed application: Set
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [[email protected]:3] Set(“SIP/201-085ae7b8”, “__EXTTOCALL=201”) in new stack
[2012-07-03 20:32:05] DEBUG[2436] app_macro.c: Executed application: Set
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [[email protected]:4] Set(“SIP/201-085ae7b8”, “__PICKUPMARK=201”) in new stack
[2012-07-03 20:32:05] DEBUG[2436] app_macro.c: Executed application: Set
[2012-07-03 20:32:05] DEBUG[2436] func_db.c: DB: CFU/201 not found in database.
[2012-07-03 20:32:05] DEBUG[2436] func_db.c: DB: CFB/201 not found in database.
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [[email protected]:5] Set(“SIP/201-085ae7b8”, “RT=”) in new stack
[2012-07-03 20:32:05] DEBUG[2436] app_macro.c: Executed application: Set
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [[email protected]:6] Gosub(“SIP/201-085ae7b8”, “sub-record-check|s|1(exten|201|)”) in new stack
[2012-07-03 20:32:05] DEBUG[2436] app_macro.c: Executed application: Gosub
[2012-07-03 20:32:05] DEBUG[2436] app_macro.c: Incrementing gosub_level
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [[email protected]:1] GotoIf(“SIP/201-085ae7b8”, “1?check”) in new stack
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Goto (sub-record-check,s,6)
[2012-07-03 20:32:05] DEBUG[2436] app_macro.c: Executed application: GotoIf
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [[email protected]:6] Set(“SIP/201-085ae7b8”, “__MON_FMT=wav”) in new stack
[2012-07-03 20:32:05] DEBUG[2436] app_macro.c: Executed application: Set
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [[email protected]:7] GotoIf(“SIP/201-085ae7b8”, “1?next”) in new stack
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Goto (sub-record-check,s,10)
[2012-07-03 20:32:05] DEBUG[2436] app_macro.c: Executed application: GotoIf
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [[email protected]:10] ExecIf(“SIP/201-085ae7b8”, “0|Return|”) in new stack
[2012-07-03 20:32:05] DEBUG[2436] app_macro.c: Executed application: ExecIf
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [[email protected]:11] GotoIf(“SIP/201-085ae7b8”, “0?novm|1”) in new stack
[2012-07-03 20:32:05] DEBUG[2436] app_macro.c: Executed application: GotoIf
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [[email protected]:12] Set(“SIP/201-085ae7b8”, “__REC_STATUS=INITIALIZED”) in new stack
[2012-07-03 20:32:05] DEBUG[2436] app_macro.c: Executed application: Set
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [[email protected]:13] ExecIf(“SIP/201-085ae7b8”, “1|Set|__REC_POLICY_MODE=0”) in new stack
[2012-07-03 20:32:05] DEBUG[2436] app_macro.c: Executed application: ExecIf
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [[email protected]:14] Set(“SIP/201-085ae7b8”, “NOW=1341361925”) in new stack
[2012-07-03 20:32:05] DEBUG[2436] app_macro.c: Executed application: Set
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [[email protected]:15] Set(“SIP/201-085ae7b8”, “__DAY=03”) in new stack
[2012-07-03 20:32:05] DEBUG[2436] app_macro.c: Executed application: Set
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [[email protected]:16] Set(“SIP/201-085ae7b8”, “__MONTH=07”) in new stack
[2012-07-03 20:32:05] DEBUG[2436] app_macro.c: Executed application: Set
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [[email protected]:17] Set(“SIP/201-085ae7b8”, “__YEAR=2012”) in new stack
[2012-07-03 20:32:05] DEBUG[2436] app_macro.c: Executed application: Set
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [[email protected]:18] Set(“SIP/201-085ae7b8”, “__TIMESTR=20120703-203205”) in new stack
[2012-07-03 20:32:05] DEBUG[2436] app_macro.c: Executed application: Set
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [[email protected]:19] Set(“SIP/201-085ae7b8”, “__FROMEXTEN=201”) in new stack
[2012-07-03 20:32:05] DEBUG[2436] app_macro.c: Executed application: Set
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [[email protected]:20] Set(“SIP/201-085ae7b8”, “__CALLFILENAME=novm-201-201-20120703-203205-1341361925.16”) in new stack
[2012-07-03 20:32:05] DEBUG[2436] app_macro.c: Executed application: Set
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [[email protected]:21] Goto(“SIP/201-085ae7b8”, “novm|1”) in new stack
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Goto (sub-record-check,novm,1)
[2012-07-03 20:32:05] DEBUG[2436] app_macro.c: Executed application: Goto
[2012-07-03 20:32:05] WARNING[2436] pbx.c: Channel ‘SIP/201-085ae7b8’ sent into invalid extension ‘novm’ in context ‘sub-record-check’, but no invalid handler
[2012-07-03 20:32:10] VERBOSE[2438] logger.c: == Parsing ‘/etc/asterisk/manager.conf’: [2012-07-03 20:32:10] VERBOSE[2438] logger.c: Found
[2012-07-03 20:32:10] VERBOSE[2438] logger.c: == Parsing ‘/etc/asterisk/manager_additional.conf’: [2012-07-03 20:32:10] VERBOSE[2438] logger.c: Found
[2012-07-03 20:32:10] VERBOSE[2438] logger.c: == Parsing ‘/etc/asterisk/manager_custom.conf’: [2012-07-03 20:32:10] VERBOSE[2438] logger.c: Found
[2012-07-03 20:32:10] WARNING[2438] manager.c: Invalid writetimeout value ‘’ at line 10

bump

I have made extensions and system recordings on them
i made ivr on them and i can listen to ivr messages but in the options i gave, if dial 1 then go to extension 100, if dial 2 then go to extension 200 but when i call from softphone and press 1 or 2, nothing happens
ivr keeps playing the message when I hit a number, it doesnt inturrupt on pressing keys, i also have marked option “enable direct dial”

I dont know where is the problem, why its not forwarding to other extensions?

It looks as if your call is from ex. 201 to ex. 201 in the above log. Is this correct? It also looks as if ex. 201 has no voicemail so if the call is from 201 to 201 then it’s bound to be busy. The error at the end about “no invalid handler” I think is a bit of a red herring as this just means there is no “i” extension in the dial plan for the extension context.

It’s best to start a new thread rather an to hijack other threads.

Thanks for responding to this and sorry for the delay in getting back to you. I have finally figured out that the forum is not notifying me of new messages no matter what I do in my account settings!

I am still having this problem. I did another test this morning and got the following. This is a call from 220 to 221.

[2012-07-19 09:10:07] WARNING[10295] rtp.c: Unable to set TOS to 184
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [[email protected]:1] Set(“SIP/220-08469640”, “__RINGTIMER=8”) in new stack
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [[email protected]:2] Macro(“SIP/220-08469640”, “exten-vm|novm|221|1|1|1”) in new stack
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [[email protected]:1] Macro(“SIP/220-08469640”, “user-callerid|”) in new stack
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [[email protected]:1] Set(“SIP/220-08469640”, “AMPUSER=220”) in new stack
[2012-07-19 09:10:07] DEBUG[10674] app_macro.c: Executed application: Set
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [[email protected]:2] GotoIf(“SIP/220-08469640”, “0?report”) in new stack
[2012-07-19 09:10:07] DEBUG[10674] app_macro.c: Executed application: GotoIf
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [[email protected]:3] ExecIf(“SIP/220-08469640”, “1|Set|REALCALLERIDNUM=220”) in new stack
[2012-07-19 09:10:07] DEBUG[10674] app_macro.c: Executed application: ExecIf
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [[email protected]:4] Set(“SIP/220-08469640”, “AMPUSER=220”) in new stack
[2012-07-19 09:10:07] DEBUG[10674] app_macro.c: Executed application: Set
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [[email protected]:5] Set(“SIP/220-08469640”, “AMPUSERCIDNAME=Office Personal”) in new stack
[2012-07-19 09:10:07] DEBUG[10674] app_macro.c: Executed application: Set
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [[email protected]:6] GotoIf(“SIP/220-08469640”, “0?report”) in new stack
[2012-07-19 09:10:07] DEBUG[10674] app_macro.c: Executed application: GotoIf
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [[email protected]:7] Set(“SIP/220-08469640”, “AMPUSERCID=220”) in new stack
[2012-07-19 09:10:07] DEBUG[10674] app_macro.c: Executed application: Set
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [[email protected]:8] Set(“SIP/220-08469640”, “CALLERID(all)=“Office Personal” <220>”) in new stack
[2012-07-19 09:10:07] DEBUG[10674] app_macro.c: Executed application: Set
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [[email protected]:9] GotoIf(“SIP/220-08469640”, “0?limit”) in new stack
[2012-07-19 09:10:07] DEBUG[10674] app_macro.c: Executed application: GotoIf
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [[email protected]:10] ExecIf(“SIP/220-08469640”, “0|Set|GROUP(concurrency_limit)=220”) in new stack
[2012-07-19 09:10:07] DEBUG[10674] app_macro.c: Executed application: ExecIf
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [[email protected]:11] ExecIf(“SIP/220-08469640”, “0|Set|CHANNEL(language)=”) in new stack
[2012-07-19 09:10:07] DEBUG[10674] app_macro.c: Executed application: ExecIf
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [[email protected]:12] GotoIf(“SIP/220-08469640”, “0?continue”) in new stack
[2012-07-19 09:10:07] DEBUG[10674] app_macro.c: Executed application: GotoIf
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [[email protected]:13] Set(“SIP/220-08469640”, “__TTL=64”) in new stack
[2012-07-19 09:10:07] DEBUG[10674] app_macro.c: Executed application: Set
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [[email protected]:14] GotoIf(“SIP/220-08469640”, “1?continue”) in new stack
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Goto (macro-user-callerid,s,25)
[2012-07-19 09:10:07] DEBUG[10674] app_macro.c: Executed application: GotoIf
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [[email protected]:25] Set(“SIP/220-08469640”, “CALLERID(number)=220”) in new stack
[2012-07-19 09:10:07] DEBUG[10674] app_macro.c: Executed application: Set
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [[email protected]:26] Set(“SIP/220-08469640”, “CALLERID(name)=Office Personal”) in new stack
[2012-07-19 09:10:07] DEBUG[10674] app_macro.c: Executed application: Set
[2012-07-19 09:10:07] DEBUG[10674] app_macro.c: Executed application: Macro
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [[email protected]:2] Set(“SIP/220-08469640”, “RingGroupMethod=none”) in new stack
[2012-07-19 09:10:07] DEBUG[10674] app_macro.c: Executed application: Set
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [[email protected]:3] Set(“SIP/220-08469640”, “__EXTTOCALL=221”) in new stack
[2012-07-19 09:10:07] DEBUG[10674] app_macro.c: Executed application: Set
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [[email protected]:4] Set(“SIP/220-08469640”, “__PICKUPMARK=221”) in new stack
[2012-07-19 09:10:07] DEBUG[10674] app_macro.c: Executed application: Set
[2012-07-19 09:10:07] DEBUG[10674] func_db.c: DB: CFU/221 not found in database.
[2012-07-19 09:10:07] DEBUG[10674] func_db.c: DB: CFB/221 not found in database.
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [[email protected]:5] Set(“SIP/220-08469640”, “RT=8”) in new stack
[2012-07-19 09:10:07] DEBUG[10674] app_macro.c: Executed application: Set
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [[email protected]:6] Gosub(“SIP/220-08469640”, “sub-record-check|s|1(exten|221|)”) in new stack
[2012-07-19 09:10:07] DEBUG[10674] app_macro.c: Executed application: Gosub
[2012-07-19 09:10:07] DEBUG[10674] app_macro.c: Incrementing gosub_level
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [[email protected]:1] GotoIf(“SIP/220-08469640”, “1?check”) in new stack
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Goto (sub-record-check,s,6)
[2012-07-19 09:10:07] DEBUG[10674] app_macro.c: Executed application: GotoIf
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [[email protected]:6] Set(“SIP/220-08469640”, “__MON_FMT=wav”) in new stack
[2012-07-19 09:10:07] DEBUG[10674] app_macro.c: Executed application: Set
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [[email protected]:7] GotoIf(“SIP/220-08469640”, “1?next”) in new stack
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Goto (sub-record-check,s,10)
[2012-07-19 09:10:07] DEBUG[10674] app_macro.c: Executed application: GotoIf
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [[email protected]:10] ExecIf(“SIP/220-08469640”, “0|Return|”) in new stack
[2012-07-19 09:10:07] DEBUG[10674] app_macro.c: Executed application: ExecIf
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [[email protected]:11] GotoIf(“SIP/220-08469640”, “0?novm|1”) in new stack
[2012-07-19 09:10:07] DEBUG[10674] app_macro.c: Executed application: GotoIf
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [[email protected]:12] Set(“SIP/220-08469640”, “__REC_STATUS=INITIALIZED”) in new stack
[2012-07-19 09:10:07] DEBUG[10674] app_macro.c: Executed application: Set
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [[email protected]:13] ExecIf(“SIP/220-08469640”, “1|Set|__REC_POLICY_MODE=1”) in new stack
[2012-07-19 09:10:07] DEBUG[10674] app_macro.c: Executed application: ExecIf
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [[email protected]:14] Set(“SIP/220-08469640”, “NOW=1342703407”) in new stack
[2012-07-19 09:10:07] DEBUG[10674] app_macro.c: Executed application: Set
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [[email protected]:15] Set(“SIP/220-08469640”, “__DAY=19”) in new stack
[2012-07-19 09:10:07] DEBUG[10674] app_macro.c: Executed application: Set
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [[email protected]:16] Set(“SIP/220-08469640”, “__MONTH=07”) in new stack
[2012-07-19 09:10:07] DEBUG[10674] app_macro.c: Executed application: Set
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [[email protected]:17] Set(“SIP/220-08469640”, “__YEAR=2012”) in new stack
[2012-07-19 09:10:07] DEBUG[10674] app_macro.c: Executed application: Set
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [[email protected]:18] Set(“SIP/220-08469640”, “__TIMESTR=20120719-091007”) in new stack
[2012-07-19 09:10:07] DEBUG[10674] app_macro.c: Executed application: Set
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [[email protected]:19] Set(“SIP/220-08469640”, “__FROMEXTEN=220”) in new stack
[2012-07-19 09:10:07] DEBUG[10674] app_macro.c: Executed application: Set
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [[email protected]:20] Set(“SIP/220-08469640”, “__CALLFILENAME=novm-221-220-20120719-091007-1342703407.7”) in new stack
[2012-07-19 09:10:07] DEBUG[10674] app_macro.c: Executed application: Set
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [[email protected]:21] Goto(“SIP/220-08469640”, “novm|1”) in new stack
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Goto (sub-record-check,novm,1)
[2012-07-19 09:10:07] DEBUG[10674] app_macro.c: Executed application: Goto
[2012-07-19 09:10:07] WARNING[10674] pbx.c: Channel ‘SIP/220-08469640’ sent into invalid extension ‘novm’ in context ‘sub-record-check’, but no invalid handler