[asterisk-r2] MF back cycle timed out

Mon Aug 22 20:41:41 CDT 2011

Hi Everyone,

I have a server with Elastix 1.6 between a PBX Panasonic D500 and Telco.
For Span 1 connect to Telco (ETB- Colombia), on Span 2 connect to PBX.
Calls from Telco work successful. On the other hand, I try to call from
PBX and always shows  "MF back cycle timed out".

Local plan is 7 digits, National plan is 10 digits, International plan
is 16 digits and Toll free is 12 digits.

S.O. Elastix     1.6-2 x 64bits
Asterisk          1.4.26.1
Dahdi              2.2.0.2-6
OpenR2          1.2.0

Configuration  /etc/dahdi/system.conf
loadzone=br
defaultzone=br

echocanceller=oslec,1-15,17-31,32-46,48-62

span=1,1,0,cas,hdb3
span=2,0,0,cas,hdb3

cas=1-15,17-31:1101
cas=32-46,48-62:1101

Configuration chan_dahdi.conf

signalling=mfcr2
mfcr2_variant=itu
mfcr2_get_ani_first=no
mfcr2_max_ani=10
mfcr2_max_dnis=3
mfcr2_category=national_subscriber
mfcr2_logdir=ETB
mfcr2_call_files=yes
mfcr2_logging=all
mfcr2_mfback_timeout=8000
mfcr2_metering_pulse_timeout=-1
mfcr2_allow_collect_calls=yes
mfcr2_double_answer=no
mfcr2_immediate_accept=no
mfcr2_forced_release=no
mfcr2_charge_calls=no

context=from-pstn
group=1
channel=>1-15,17-31

mfcr2_max_ani=3
mfcr2_max_dnis=16

context=from-internal
group=2
channel=>32-46,48-62

[19:46:21:137] [Thread: 1095342400] [Chan 54] - Call started at Mon Aug
22 19:46:21 2011 on chan 54 [openr2 version 1.2.0, revision exported]
[19:46:21:137] [Thread: 1095342400] [Chan 54] - CAS Tx>>  [SEIZE ACK] 0x0C
[19:46:21:137] [Thread: 1095342400] [Chan 54] - CAS Raw Tx>>  0x0D
[19:46:21:448] [Thread: 1095342400] [Chan 54] - MF Rx<<  7 [ON]
[19:46:21:448] [Thread: 1095342400] [Chan 54] - Attempting to cancel
timer timer 0
[19:46:21:448] [Thread: 1095342400] [Chan 54] - Cannot cancel timer 0
[19:46:21:448] [Thread: 1095342400] [Chan 54] - Getting DNIS digit 7
[19:46:21:448] [Thread: 1095342400] [Chan 54] - DNIS so far: 7, expected
length: 16
[19:46:21:449] [Thread: 1095342400] [Chan 54] - Requesting next DNIS
with signal 0x31.
[19:46:21:449] [Thread: 1095342400] [Chan 54] - MF Tx>>  1 [ON]
[19:46:21:449] [Thread: 1095342400] [Chan 54] - scheduled timer id 2
(mf_back_cycle)
[19:46:21:528] [Thread: 1095342400] [Chan 54] - MF Rx<<  7 [OFF]
[19:46:21:528] [Thread: 1095342400] [Chan 54] - MF Tx>>  1 [OFF]
[19:46:21:688] [Thread: 1095342400] [Chan 54] - MF Rx<<  4 [ON]
[19:46:21:688] [Thread: 1095342400] [Chan 54] - Attempting to cancel
timer timer 2
[19:46:21:688] [Thread: 1095342400] [Chan 54] - timer id 2 found,
cancelling it now
[19:46:21:688] [Thread: 1095342400] [Chan 54] - Getting DNIS digit 4
[19:46:21:688] [Thread: 1095342400] [Chan 54] - DNIS so far: 74,
expected length: 16
[19:46:21:689] [Thread: 1095342400] [Chan 54] - Requesting next DNIS
with signal 0x31.
[19:46:21:689] [Thread: 1095342400] [Chan 54] - MF Tx>>  1 [ON]
[19:46:21:689] [Thread: 1095342400] [Chan 54] - scheduled timer id 3
(mf_back_cycle)
[19:46:21:748] [Thread: 1095342400] [Chan 54] - MF Rx<<  4 [OFF]
[19:46:21:748] [Thread: 1095342400] [Chan 54] - MF Tx>>  1 [OFF]
[19:46:21:928] [Thread: 1095342400] [Chan 54] - MF Rx<<  2 [ON]
[19:46:21:928] [Thread: 1095342400] [Chan 54] - Attempting to cancel
timer timer 3
[19:46:21:928] [Thread: 1095342400] [Chan 54] - timer id 3 found,
cancelling it now
[19:46:21:928] [Thread: 1095342400] [Chan 54] - Getting DNIS digit 2
[19:46:21:928] [Thread: 1095342400] [Chan 54] - DNIS so far: 742,
expected length: 16
[19:46:21:929] [Thread: 1095342400] [Chan 54] - Requesting next DNIS
with signal 0x31.
[19:46:21:929] [Thread: 1095342400] [Chan 54] - MF Tx>>  1 [ON]
[19:46:21:929] [Thread: 1095342400] [Chan 54] - scheduled timer id 4
(mf_back_cycle)
[19:46:21:988] [Thread: 1095342400] [Chan 54] - MF Rx<<  2 [OFF]
[19:46:21:988] [Thread: 1095342400] [Chan 54] - MF Tx>>  1 [OFF]
[19:46:22:268] [Thread: 1095342400] [Chan 54] - MF Rx<<  4 [ON]
[19:46:22:268] [Thread: 1095342400] [Chan 54] - Attempting to cancel
timer timer 4
[19:46:22:268] [Thread: 1095342400] [Chan 54] - timer id 4 found,
cancelling it now
[19:46:22:268] [Thread: 1095342400] [Chan 54] - Getting DNIS digit 4
[19:46:22:268] [Thread: 1095342400] [Chan 54] - DNIS so far: 7424,
expected length: 16
[19:46:22:269] [Thread: 1095342400] [Chan 54] - Requesting next DNIS
with signal 0x31.
[19:46:22:269] [Thread: 1095342400] [Chan 54] - MF Tx>>  1 [ON]
[19:46:22:269] [Thread: 1095342400] [Chan 54] - scheduled timer id 5
(mf_back_cycle)
[19:46:22:328] [Thread: 1095342400] [Chan 54] - MF Rx<<  4 [OFF]
[19:46:22:328] [Thread: 1095342400] [Chan 54] - MF Tx>>  1 [OFF]
[19:46:22:788] [Thread: 1095342400] [Chan 54] - MF Rx<<  0 [ON]
[19:46:22:788] [Thread: 1095342400] [Chan 54] - Attempting to cancel
timer timer 5
[19:46:22:788] [Thread: 1095342400] [Chan 54] - timer id 5 found,
cancelling it now
[19:46:22:788] [Thread: 1095342400] [Chan 54] - Getting DNIS digit 0
[19:46:22:788] [Thread: 1095342400] [Chan 54] - DNIS so far: 74240,
expected length: 16
[19:46:22:789] [Thread: 1095342400] [Chan 54] - Requesting next DNIS
with signal 0x31.
[19:46:22:789] [Thread: 1095342400] [Chan 54] - MF Tx>>  1 [ON]
[19:46:22:789] [Thread: 1095342400] [Chan 54] - scheduled timer id 6
(mf_back_cycle)
[19:46:22:868] [Thread: 1095342400] [Chan 54] - MF Rx<<  0 [OFF]
[19:46:22:868] [Thread: 1095342400] [Chan 54] - MF Tx>>  1 [OFF]
[19:46:23:129] [Thread: 1095342400] [Chan 54] - MF Rx<<  0 [ON]
[19:46:23:129] [Thread: 1095342400] [Chan 54] - Attempting to cancel
timer timer 6
[19:46:23:129] [Thread: 1095342400] [Chan 54] - timer id 6 found,
cancelling it now
[19:46:23:129] [Thread: 1095342400] [Chan 54] - Getting DNIS digit 0
[19:46:23:129] [Thread: 1095342400] [Chan 54] - DNIS so far: 742400,
expected length: 16
[19:46:23:129] [Thread: 1095342400] [Chan 54] - Requesting next DNIS
with signal 0x31.
[19:46:23:129] [Thread: 1095342400] [Chan 54] - MF Tx>>  1 [ON]
[19:46:23:129] [Thread: 1095342400] [Chan 54] - scheduled timer id 7
(mf_back_cycle)
[19:46:23:208] [Thread: 1095342400] [Chan 54] - MF Rx<<  0 [OFF]
[19:46:23:208] [Thread: 1095342400] [Chan 54] - MF Tx>>  1 [OFF]
[19:46:23:568] [Thread: 1095342400] [Chan 54] - MF Rx<<  0 [ON]
[19:46:23:568] [Thread: 1095342400] [Chan 54] - Attempting to cancel
timer timer 7
[19:46:23:568] [Thread: 1095342400] [Chan 54] - timer id 7 found,
cancelling it now
[19:46:23:568] [Thread: 1095342400] [Chan 54] - Getting DNIS digit 0
[19:46:23:568] [Thread: 1095342400] [Chan 54] - DNIS so far: 7424000,
expected length: 16
[19:46:23:569] [Thread: 1095342400] [Chan 54] - Requesting next DNIS
with signal 0x31.
[19:46:23:569] [Thread: 1095342400] [Chan 54] - MF Tx>>  1 [ON]
[19:46:23:569] [Thread: 1095342400] [Chan 54] - scheduled timer id 8
(mf_back_cycle)
[19:46:23:648] [Thread: 1095342400] [Chan 54] - MF Rx<<  0 [OFF]
[19:46:23:648] [Thread: 1095342400] [Chan 54] - MF Tx>>  1 [OFF]
[19:46:31:568] [Thread: 1095342400] [Chan 54] - Attempting to cancel
timer timer 8
[19:46:31:568] [Thread: 1095342400] [Chan 54] - timer id 8 found,
cancelling it now
[19:46:31:568] [Thread: 1095342400] [Chan 54] - calling timer 8
(mf_back_cycle) callback
[19:46:31:569] [Thread: 1095342400] [Chan 54] - MF back cycle timed out!
[19:46:31:569] [Thread: 1095342400] [Chan 54] - Protocol error. Reason =
Multi Frequency Cycle Timeout, R2 State = Seize ACK Transmitted, MF
state = DNIS Request Transmitted, MF Group = Backward Group A, CAS = 0x00
DNIS = 7424000, ANI = , MF = 0x20
[19:46:31:569] [Thread: 1095342400] [Chan 54] - Attempting to cancel
timer timer 0
[19:46:31:569] [Thread: 1095342400] [Chan 54] - Cannot cancel timer 0

Thanks a lot,

-- 
Ing. César Augusto Bonilla A.
Ingeniero de Nuevos Productos
HIT Colombia