[Sep 7 11:08:57] VERBOSE[8287] logger.c: -- Executing [90034934009300@from-internal:1] Macro("SIP/6419-b7b3e770", "user-callerid|SKIPTTL|") in new stack
[Sep 7 11:08:57] VERBOSE[8287] logger.c: -- Executing [s@macro-user-callerid:1] Set("SIP/6419-b7b3e770", "AMPUSER=6419") in new stack
[Sep 7 11:08:57] DEBUG[8287] app_macro.c: Executed application: Set
[Sep 7 11:08:57] VERBOSE[8287] logger.c: -- Executing [s@macro-user-callerid:2] GotoIf("SIP/6419-b7b3e770", "0?report") in new stack
[Sep 7 11:08:57] DEBUG[8287] app_macro.c: Executed application: GotoIf
[Sep 7 11:08:57] VERBOSE[8287] logger.c: -- Executing [s@macro-user-callerid:3] ExecIf("SIP/6419-b7b3e770", "1|Set|REALCALLERIDNUM=6419") in new stack
[Sep 7 11:08:57] DEBUG[8287] app_macro.c: Executed application: ExecIf
[Sep 7 11:08:57] VERBOSE[8287] logger.c: -- Executing [s@macro-user-callerid:4] Set("SIP/6419-b7b3e770", "AMPUSER=6419") in new stack
[Sep 7 11:08:57] DEBUG[8287] app_macro.c: Executed application: Set
[Sep 7 11:08:57] VERBOSE[8287] logger.c: -- Executing [s@macro-user-callerid:5] Set("SIP/6419-b7b3e770", "AMPUSERCIDNAME=GONZALEZ JAVIER") in new stack
[Sep 7 11:08:57] DEBUG[8287] app_macro.c: Executed application: Set
[Sep 7 11:08:57] VERBOSE[8287] logger.c: -- Executing [s@macro-user-callerid:6] GotoIf("SIP/6419-b7b3e770", "0?report") in new stack
[Sep 7 11:08:57] DEBUG[8287] app_macro.c: Executed application: GotoIf
[Sep 7 11:08:57] VERBOSE[8287] logger.c: -- Executing [s@macro-user-callerid:7] Set("SIP/6419-b7b3e770", "AMPUSERCID=6419") in new stack
[Sep 7 11:08:57] DEBUG[8287] app_macro.c: Executed application: Set
[Sep 7 11:08:57] VERBOSE[8287] logger.c: -- Executing [s@macro-user-callerid:8] Set("SIP/6419-b7b3e770", "CALLERID(all)="GONZALEZ JAVIER" <6419>") in new stack
[Sep 7 11:08:57] DEBUG[8287] app_macro.c: Executed application: Set
[Sep 7 11:08:57] VERBOSE[8287] logger.c: -- Executing [s@macro-user-callerid:9] Set("SIP/6419-b7b3e770", "REALCALLERIDNUM=6419") in new stack
[Sep 7 11:08:57] DEBUG[8287] app_macro.c: Executed application: Set
[Sep 7 11:08:57] VERBOSE[8287] logger.c: -- Executing [s@macro-user-callerid:10] ExecIf("SIP/6419-b7b3e770", "1|Set|CHANNEL(language)=es") in new stack
[Sep 7 11:08:57] DEBUG[8287] app_macro.c: Executed application: ExecIf
[Sep 7 11:08:57] DEBUG[8287] app_macro.c: Last app: Set|CHANNEL(language)=es
[Sep 7 11:08:57] VERBOSE[8287] logger.c: -- Executing [s@macro-user-callerid:11] GotoIf("SIP/6419-b7b3e770", "1?continue") in new stack
[Sep 7 11:08:57] VERBOSE[8287] logger.c: -- Goto (macro-user-callerid,s,20)
[Sep 7 11:08:57] DEBUG[8287] app_macro.c: Executed application: GotoIf
[Sep 7 11:08:57] VERBOSE[8287] logger.c: -- Executing [s@macro-user-callerid:20] NoOp("SIP/6419-b7b3e770", "Using CallerID "GONZALEZ JAVIER" <6419>") in new stack
[Sep 7 11:08:57] DEBUG[8287] app_macro.c: Executed application: Noop
[Sep 7 11:08:57] VERBOSE[8287] logger.c: -- Executing [90034934009300@from-internal:2] Macro("SIP/6419-b7b3e770", "pinsets|5|0") in new stack
[Sep 7 11:08:57] VERBOSE[8287] logger.c: -- Executing [s@macro-pinsets:1] GotoIf("SIP/6419-b7b3e770", "0 = 1?cdr|1") in new stack
[Sep 7 11:08:57] DEBUG[8287] app_macro.c: Executed application: GotoIf
[Sep 7 11:08:57] DEBUG[8287] func_db.c: DB: AMPUSER/6419/pinless not found in database.
[Sep 7 11:08:57] VERBOSE[8287] logger.c: -- Executing [s@macro-pinsets:2] ExecIf("SIP/6419-b7b3e770", "1|Authenticate|/etc/asterisk/pinset_5") in new stack
[Sep 7 11:08:57] VERBOSE[8287] logger.c: -- <SIP/6419-b7b3e770> Playing 'agent-pass' (language 'es')
[Sep 7 11:08:59] VERBOSE[8287] logger.c: -- <SIP/6419-b7b3e770> Playing 'auth-thankyou' (language 'es')
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: ExecIf
[Sep 7 11:09:00] DEBUG[8287] func_db.c: DB: AMPUSER/6419/pinless not found in database.
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Last app: Authenticate|/etc/asterisk/pinset_5
[Sep 7 11:09:00] DEBUG[8287] func_db.c: DB: AMPUSER/6419/pinless not found in database.
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-pinsets:3] ExecIf("SIP/6419-b7b3e770", "1|ResetCDR|") in new stack
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: ExecIf
[Sep 7 11:09:00] DEBUG[8287] func_db.c: DB: AMPUSER/6419/pinless not found in database.
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Last app: ResetCDR|
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [90034934009300@from-internal:3] Set("SIP/6419-b7b3e770", "_NODEST=") in new stack
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [90034934009300@from-internal:4] Macro("SIP/6419-b7b3e770", "record-enable|6419|OUT|") in new stack
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-record-enable:1] GotoIf("SIP/6419-b7b3e770", "1?check") in new stack
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Goto (macro-record-enable,s,4)
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: GotoIf
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-record-enable:4] AGI("SIP/6419-b7b3e770", "recordingcheck|20090907-110900|1252339737.23") in new stack
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
[Sep 7 11:09:00] VERBOSE[8287] logger.c: recordingcheck|20090907-110900|1252339737.23: Outbound recording not enabled
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- AGI Script recordingcheck completed, returning 0
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: AGI
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-record-enable:5] MacroExit("SIP/6419-b7b3e770", "") in new stack
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [90034934009300@from-internal:5] Macro("SIP/6419-b7b3e770", "dialout-trunk|2|0034934009300||") in new stack
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-dialout-trunk:1] Set("SIP/6419-b7b3e770", "DIAL_TRUNK=2") in new stack
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: Set
[Sep 7 11:09:00] DEBUG[8287] func_db.c: DB: AMPUSER/6419/pinless not found in database.
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-dialout-trunk:2] GosubIf("SIP/6419-b7b3e770", "0?sub-pincheck|s|1") in new stack
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: GosubIf
[Sep 7 11:09:00] DEBUG[8287] func_db.c: DB: AMPUSER/6419/pinless not found in database.
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-dialout-trunk:3] GotoIf("SIP/6419-b7b3e770", "0?disabletrunk|1") in new stack
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: GotoIf
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-dialout-trunk:4] Set("SIP/6419-b7b3e770", "DIAL_NUMBER=0034934009300") in new stack
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: Set
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-dialout-trunk:5] Set("SIP/6419-b7b3e770", "DIAL_TRUNK_OPTIONS=tr") in new stack
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: Set
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-dialout-trunk:6] Set("SIP/6419-b7b3e770", "OUTBOUND_GROUP=OUT_2") in new stack
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: Set
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-dialout-trunk:7] GotoIf("SIP/6419-b7b3e770", "1?nomax") in new stack
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Goto (macro-dialout-trunk,s,9)
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: GotoIf
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-dialout-trunk:9] GotoIf("SIP/6419-b7b3e770", "0?skipoutcid") in new stack
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: GotoIf
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-dialout-trunk:10] Set("SIP/6419-b7b3e770", "DIAL_TRUNK_OPTIONS=") in new stack
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: Set
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-dialout-trunk:11] Macro("SIP/6419-b7b3e770", "outbound-callerid|2") in new stack
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-outbound-callerid:1] ExecIf("SIP/6419-b7b3e770", "0|SetCallerPres|") in new stack
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: ExecIf
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-outbound-callerid:2] ExecIf("SIP/6419-b7b3e770", "0|Set|REALCALLERIDNUM=6419") in new stack
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: ExecIf
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-outbound-callerid:3] GotoIf("SIP/6419-b7b3e770", "1?normcid") in new stack
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Goto (macro-outbound-callerid,s,6)
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: GotoIf
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-outbound-callerid:6] Set("SIP/6419-b7b3e770", "USEROUTCID=") in new stack
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: Set
[Sep 7 11:09:00] DEBUG[8287] func_db.c: DB: DEVICE/6419/emergency_cid not found in database.
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-outbound-callerid:7] Set("SIP/6419-b7b3e770", "EMERGENCYCID=") in new stack
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: Set
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-outbound-callerid:8] Set("SIP/6419-b7b3e770", "TRUNKOUTCID=") in new stack
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: Set
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-outbound-callerid:9] GotoIf("SIP/6419-b7b3e770", "1?trunkcid") in new stack
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Goto (macro-outbound-callerid,s,12)
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: GotoIf
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-outbound-callerid:12] ExecIf("SIP/6419-b7b3e770", "0|Set|CALLERID(all)=") in new stack
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: ExecIf
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-outbound-callerid:13] ExecIf("SIP/6419-b7b3e770", "0|Set|CALLERID(all)=") in new stack
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: ExecIf
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-outbound-callerid:14] ExecIf("SIP/6419-b7b3e770", "0|SetCallerPres|prohib_passed_screen") in new stack
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: ExecIf
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: Macro
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-dialout-trunk:12] ExecIf("SIP/6419-b7b3e770", "0|AGI|fixlocalprefix") in new stack
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: ExecIf
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-dialout-trunk:13] Set("SIP/6419-b7b3e770", "OUTNUM=0034934009300") in new stack
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: Set
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-dialout-trunk:14] Set("SIP/6419-b7b3e770", "custom=AMP") in new stack
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: Set
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-dialout-trunk:15] ExecIf("SIP/6419-b7b3e770", "0|Set|DIAL_TRUNK_OPTIONS=M(setmusic^)") in new stack
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: ExecIf
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-dialout-trunk:16] Macro("SIP/6419-b7b3e770", "dialout-trunk-predial-hook|") in new stack
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-dialout-trunk-predial-hook:1] Set("SIP/6419-b7b3e770", "DIRNAME=20090907") in new stack
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: Set
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-dialout-trunk-predial-hook:2] Set("SIP/6419-b7b3e770", "CTECH=SIP") in new stack
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: Set
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-dialout-trunk-predial-hook:3] Set("SIP/6419-b7b3e770", "CNUM=6419-b7b3e770") in new stack
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: Set
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-dialout-trunk-predial-hook:4] Set("SIP/6419-b7b3e770", "FILENAME=20090907-110900--SIP-6419-b7b3e770") in new stack
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: Set
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: Macro
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-dialout-trunk:17] GotoIf("SIP/6419-b7b3e770", "0?bypass|1") in new stack
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: GotoIf
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-dialout-trunk:18] GotoIf("SIP/6419-b7b3e770", "1?customtrunk") in new stack
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Goto (macro-dialout-trunk,s,21)
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: GotoIf
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-dialout-trunk:21] Set("SIP/6419-b7b3e770", "pre_num=AMP:DAHDI/g1/") in new stack
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: Set
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-dialout-trunk:22] Set("SIP/6419-b7b3e770", "the_num=OUTNUM") in new stack
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: Set
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-dialout-trunk:23] Set("SIP/6419-b7b3e770", "post_num=") in new stack
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: Set
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-dialout-trunk:24] GotoIf("SIP/6419-b7b3e770", "1?outnum:skipoutnum") in new stack
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Goto (macro-dialout-trunk,s,25)
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: GotoIf
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-dialout-trunk:25] Set("SIP/6419-b7b3e770", "the_num=0034934009300") in new stack
[Sep 7 11:09:00] DEBUG[8287] app_macro.c: Executed application: Set
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Executing [s@macro-dialout-trunk:26] Dial("SIP/6419-b7b3e770", "DAHDI/g1/0034934009300|300|") in new stack
[Sep 7 11:09:00] DEBUG[8287] chan_dahdi.c: no MFC/R2 category specified for chan DAHDI/4-1, using default National Subscriber
[Sep 7 11:09:00] DEBUG[8287] chan_dahdi.c: Chan 4 - Attempting to make call (ANI=6419, DNIS=0034934009300, category=National Subscriber)
[Sep 7 11:09:00] DEBUG[8287] chan_dahdi.c: Chan 4 - Call started at Mon Sep 7 11:09:00 2009 on chan 4
[Sep 7 11:09:00] DEBUG[8287] chan_dahdi.c: Chan 4 - CAS Tx >> [SEIZE] 0x00
[Sep 7 11:09:00] DEBUG[8287] chan_dahdi.c: Chan 4 - CAS Raw Tx >> 0x01
[Sep 7 11:09:00] VERBOSE[8287] logger.c: -- Called g1/0034934009300
[Sep 7 11:09:00] DEBUG[8287] chan_dahdi.c: bits changed in chan 4
[Sep 7 11:09:00] DEBUG[8287] chan_dahdi.c: Chan 4 - Bits changed from 0x08 to 0x0C
[Sep 7 11:09:00] DEBUG[8287] chan_dahdi.c: Chan 4 - CAS Rx << [SEIZE ACK] 0x0C
[Sep 7 11:09:00] DEBUG[8287] chan_dahdi.c: Chan 4 - Sending DNIS digit 0
[Sep 7 11:09:00] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Tx >> 0 [ON]
[Sep 7 11:09:00] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Rx << 1 [ON]
[Sep 7 11:09:00] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Tx >> 0 [OFF]
[Sep 7 11:09:00] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Rx << 1 [OFF]
[Sep 7 11:09:00] DEBUG[8287] chan_dahdi.c: Chan 4 - Sending DNIS digit 0
[Sep 7 11:09:00] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Tx >> 0 [ON]
[Sep 7 11:09:00] DEBUG[8287] chan_dahdi.c: Chan 4 - Group A DNIS request handled
[Sep 7 11:09:00] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Rx << 1 [ON]
[Sep 7 11:09:00] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Tx >> 0 [OFF]
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Rx << 1 [OFF]
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - Sending DNIS digit 3
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Tx >> 3 [ON]
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - Group A DNIS request handled
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Rx << 1 [ON]
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Tx >> 3 [OFF]
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Rx << 1 [OFF]
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - Sending DNIS digit 4
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Tx >> 4 [ON]
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - Group A DNIS request handled
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Rx << 1 [ON]
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Tx >> 4 [OFF]
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Rx << 1 [OFF]
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - Sending DNIS digit 9
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Tx >> 9 [ON]
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - Group A DNIS request handled
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Rx << 1 [ON]
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Tx >> 9 [OFF]
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Rx << 1 [OFF]
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - Sending DNIS digit 3
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Tx >> 3 [ON]
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - Group A DNIS request handled
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Rx << 1 [ON]
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Tx >> 3 [OFF]
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Rx << 1 [OFF]
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - Sending DNIS digit 4
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Tx >> 4 [ON]
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - Group A DNIS request handled
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Rx << 1 [ON]
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Tx >> 4 [OFF]
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Rx << 1 [OFF]
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - Sending DNIS digit 0
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Tx >> 0 [ON]
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - Group A DNIS request handled
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Rx << 1 [ON]
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Tx >> 0 [OFF]
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Rx << 1 [OFF]
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - Sending DNIS digit 0
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Tx >> 0 [ON]
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - Group A DNIS request handled
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Rx << 1 [ON]
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Tx >> 0 [OFF]
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Rx << 1 [OFF]
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - Sending DNIS digit 9
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Tx >> 9 [ON]
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - Group A DNIS request handled
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Rx << 1 [ON]
[Sep 7 11:09:01] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Tx >> 9 [OFF]
[Sep 7 11:09:02] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Rx << 1 [OFF]
[Sep 7 11:09:02] DEBUG[8287] chan_dahdi.c: Chan 4 - Sending DNIS digit 3
[Sep 7 11:09:02] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Tx >> 3 [ON]
[Sep 7 11:09:02] DEBUG[8287] chan_dahdi.c: Chan 4 - Group A DNIS request handled
[Sep 7 11:09:02] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Rx << 1 [ON]
[Sep 7 11:09:02] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Tx >> 3 [OFF]
[Sep 7 11:09:02] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Rx << 1 [OFF]
[Sep 7 11:09:02] DEBUG[8287] chan_dahdi.c: Chan 4 - Sending DNIS digit 0
[Sep 7 11:09:02] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Tx >> 0 [ON]
[Sep 7 11:09:02] DEBUG[8287] chan_dahdi.c: Chan 4 - Group A DNIS request handled
[Sep 7 11:09:02] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Rx << 1 [ON]
[Sep 7 11:09:02] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Tx >> 0 [OFF]
[Sep 7 11:09:02] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Rx << 1 [OFF]
[Sep 7 11:09:02] DEBUG[8287] chan_dahdi.c: Chan 4 - Sending DNIS digit 0
[Sep 7 11:09:02] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Tx >> 0 [ON]
[Sep 7 11:09:02] DEBUG[8287] chan_dahdi.c: Chan 4 - Group A DNIS request handled
[Sep 7 11:09:02] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Rx << 1 [ON]
[Sep 7 11:09:02] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Tx >> 0 [OFF]
[Sep 7 11:09:02] DEBUG[8287] chan_dahdi.c: Chan 4 - MF Rx << 1 [OFF]
[Sep 7 11:09:02] DEBUG[8287] chan_dahdi.c: Chan 4 - No more DNIS. Doing nothing, waiting for timeout.
[Sep 7 11:09:02] DEBUG[8287] chan_dahdi.c: Chan 4 - Group A DNIS request handled
[Sep 7 11:09:12] DEBUG[8287] chan_dahdi.c: Chan 4 - calling timer callback
[Sep 7 11:09:12] ERROR[8287] chan_dahdi.c: Chan 4 - Protocol error. Reason = Forward Safety Timeout, R2 State = Seize ACK Received, MF state = Waiting Far End Timeout, MF Group = Forward Group I, CAS = 0x0C
[Sep 7 11:09:12] DEBUG[8287] chan_dahdi.c: Chan 4 - CAS Tx >> [IDLE] 0x08
[Sep 7 11:09:12] DEBUG[8287] chan_dahdi.c: Chan 4 - CAS Raw Tx >> 0x09
[Sep 7 11:09:12] ERROR[8287] chan_dahdi.c: MFC/R2 protocol error on chan 4: Forward Safety Timeout
[Sep 7 11:09:12] DEBUG[8287] chan_dahdi.c: disconnecting MFC/R2 call on chan 4
[Sep 7 11:09:12] VERBOSE[8287] logger.c: -- Hungup 'DAHDI/4-1'
[Sep 7 11:09:12] VERBOSE[8287] logger.c: == Everyone is busy/congested at this time (1:0/0/1)
[Sep 7 11:09:12] DEBUG[8287] app_macro.c: Executed application: Dial
[Sep 7 11:09:12] VERBOSE[8287] logger.c: -- Executing [s@macro-dialout-trunk:27] Goto("SIP/6419-b7b3e770", "s-CHANUNAVAIL|1") in new stack
[Sep 7 11:09:12] VERBOSE[8287] logger.c: -- Goto (macro-dialout-trunk,s-CHANUNAVAIL,1)
[Sep 7 11:09:12] DEBUG[8287] app_macro.c: Executed application: Goto
[Sep 7 11:09:12] VERBOSE[8287] logger.c: -- Executing [s-CHANUNAVAIL@macro-dialout-trunk:1] GotoIf("SIP/6419-b7b3e770", "1?noreport") in new stack
[Sep 7 11:09:12] VERBOSE[8287] logger.c: -- Goto (macro-dialout-trunk,s-CHANUNAVAIL,3)
[Sep 7 11:09:12] DEBUG[8287] app_macro.c: Executed application: GotoIf
[Sep 7 11:09:12] VERBOSE[8287] logger.c: -- Executing [s-CHANUNAVAIL@macro-dialout-trunk:3] NoOp("SIP/6419-b7b3e770", "TRUNK Dial failed due to CHANUNAVAIL (hangupcause: 111) - failing through to other trunks") in new stack
[Sep 7 11:09:12] DEBUG[8287] app_macro.c: Executed application: Noop
[Sep 7 11:09:12] VERBOSE[8287] logger.c: -- Executing [90034934009300@from-internal:6] Macro("SIP/6419-b7b3e770", "outisbusy|") in new stack
[Sep 7 11:09:12] VERBOSE[8287] logger.c: -- Executing [s@macro-outisbusy:1] Playback("SIP/6419-b7b3e770", "all-circuits-busy-now|noanswer") in new stack
[Sep 7 11:09:12] VERBOSE[8287] logger.c: -- <SIP/6419-b7b3e770> Playing 'all-circuits-busy-now' (language 'es')
[Sep 7 11:09:14] DEBUG[8287] app_macro.c: Executed application: Playback
[Sep 7 11:09:14] VERBOSE[8287] logger.c: -- Executing [s@macro-outisbusy:2] Playback("SIP/6419-b7b3e770", "pls-try-call-later|noanswer") in new stack
[Sep 7 11:09:14] VERBOSE[8287] logger.c: -- <SIP/6419-b7b3e770> Playing 'pls-try-call-later' (language 'es')
[Sep 7 11:09:15] VERBOSE[8287] logger.c: == Spawn extension (macro-outisbusy, s, 2) exited non-zero on 'SIP/6419-b7b3e770' in macro 'outisbusy'
[Sep 7 11:09:15] VERBOSE[8287] logger.c: == Spawn extension (from-internal, 90034934009300, 6) exited non-zero on 'SIP/6419-b7b3e770'
[Sep 7 11:09:15] VERBOSE[8287] logger.c: -- Executing [h@from-internal:1] Macro("SIP/6419-b7b3e770", "hangupcall") in new stack
[Sep 7 11:09:15] VERBOSE[8287] logger.c: -- Executing [s@macro-hangupcall:1] ResetCDR("SIP/6419-b7b3e770", "vw") in new stack
[Sep 7 11:09:15] DEBUG[8287] app_macro.c: Executed application: ResetCDR
[Sep 7 11:09:15] VERBOSE[8287] logger.c: -- Executing [s@macro-hangupcall:2] NoCDR("SIP/6419-b7b3e770", "") in new stack
[Sep 7 11:09:15] DEBUG[8287] app_macro.c: Executed application: NoCDR
[Sep 7 11:09:15] VERBOSE[8287] logger.c: -- Executing [s@macro-hangupcall:3] GotoIf("SIP/6419-b7b3e770", "1?skiprg") in new stack
[Sep 7 11:09:15] VERBOSE[8287] logger.c: -- Goto (macro-hangupcall,s,6)
[Sep 7 11:09:15] DEBUG[8287] app_macro.c: Executed application: GotoIf
[Sep 7 11:09:15] VERBOSE[8287] logger.c: -- Executing [s@macro-hangupcall:6] GotoIf("SIP/6419-b7b3e770", "1?skipblkvm") in new stack
[Sep 7 11:09:15] VERBOSE[8287] logger.c: -- Goto (macro-hangupcall,s,9)
[Sep 7 11:09:15] DEBUG[8287] app_macro.c: Executed application: GotoIf
[Sep 7 11:09:15] VERBOSE[8287] logger.c: -- Executing [s@macro-hangupcall:9] GotoIf("SIP/6419-b7b3e770", "1?theend") in new stack
[Sep 7 11:09:15] VERBOSE[8287] logger.c: -- Goto (macro-hangupcall,s,11)
[Sep 7 11:09:15] DEBUG[8287] app_macro.c: Executed application: GotoIf
[Sep 7 11:09:15] VERBOSE[8287] logger.c: -- Executing [s@macro-hangupcall:11] Hangup("SIP/6419-b7b3e770", "") in new stack
[Sep 7 11:09:15] VERBOSE[8287] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'SIP/6419-b7b3e770' in macro 'hangupcall'
[Sep 7 11:09:15] VERBOSE[8287] logger.c: == Spawn extension
(from-internal, s, 1) exited non-zero on 'SIP/6419-b7b3e770'
Revisando algunos correos de la lista me encontre con que es un error
en el tiempo de espera, ya lo aumente el tiempo de espera en el archivo
r2proto.conf quedo de la siguiente manera
# Timers in milliseconds
# Use -1 to leave default, or just comment it out for that matter
timers.mf_back_cycle=1500
timers.mf_back_resume_cycle=150
timers.mf_fwd_safety=14000
timers.r2_seize=8000
timers.r2_answer=80000
timers.r2_metering_pulse=0
timers.r2_double_answer=0
timers.r2_answer_delay=150
timers.cas_persistence_check=500
Le puse 14000 por revisaron los de telmex y dejeron que todo estaba
bien y que 14 segs es lo que se tarda en conectar una llamada
internacional pero el efecto es el mismo.
Alguien tiene alguna sugerencia?
Sera un bug en open/R2
Asterisk 1.4.24.1
openr2-1.1.0
Todo lo demas funciona bien.
Saludos.
Buff... lo de siempre, que esto es una lista de Asterisk y no un foro de
soporte sobre Asterisk enlatados con AGI's infernales.
--
Iñaki Baz Castillo
<ib...@xtratelecom.es>
>
> El Monday 07 September 2009 18:25:22 Alvaro Colunga escribió:
> > Saludos, tengo un problema al intentar marcar numeros
> > internacionales, algunos destinos me funcionan otros no, aqui
> > muestro la salida del CLI
>
> Buff... lo de siempre, que esto es una lista de Asterisk y no un foro
> de soporte sobre Asterisk enlatados con AGI's infernales.
>
El problema no es el enlatado es con el enlace, si hago la llamada
directamente sin usar los agis, el resultado es el mismo.
Saludos.
Ok, entiendo. pero si pudieses limpiar todo lo no relevante al problema en sí
(verbose de los AGI's) y probar el error "a pelo" sería mucha
más "agradable" :)