Extension to Extension calling not working

simonmason · July 4, 2012, 12:41am

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 [201@from-internal:1] Set(“SIP/201-085ae7b8”, “__RINGTIMER=8”) in new stack
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [201@from-internal: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 [s@macro-exten-vm:1] Macro(“SIP/201-085ae7b8”, “user-callerid|”) in new stack
[2012-07-03 20:32:05] VERBOSE[2436] logger.c: – Executing [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-exten-vm: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 [s@macro-exten-vm: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 [s@macro-exten-vm: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 [s@macro-exten-vm: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 [s@macro-exten-vm: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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

simonmason · July 12, 2012, 12:28am

bump

momal · July 13, 2012, 1:08pm

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?

leemason · July 14, 2012, 1:49pm

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.

leemason · July 14, 2012, 1:50pm

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

simonmason · July 19, 2012, 1:12pm

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 [221@from-internal:1] Set(“SIP/220-08469640”, “__RINGTIMER=8”) in new stack
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [221@from-internal: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 [s@macro-exten-vm:1] Macro(“SIP/220-08469640”, “user-callerid|”) in new stack
[2012-07-19 09:10:07] VERBOSE[10674] logger.c: – Executing [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-user-callerid: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 [s@macro-exten-vm: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 [s@macro-exten-vm: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 [s@macro-exten-vm: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 [s@macro-exten-vm: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 [s@macro-exten-vm: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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 [s@sub-record-check: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