[asterisk-r2] mfcr2 incoming call problem

Mon Nov 29 16:51:04 CST 2010

Hi there!
 I am trying set up an E1 link but something really stranger happens:
 When I receive a call and pick up the phone I receive busy tone and then the call ring again, if I answer for the second times again I receive busy tone and the call ring once more....
in my /var/log/asterisk/mfcr2/span1 I see three files after a test:
chan-1-backward-4-20101129183656.call  chan-2-backward-3-20101129183701.call  chan-3-backward-2-20101129183706.call
This is one of those:
[18:45:23:676] [Thread: 3058592656] [Chan 1] - Call started at Mon Nov 29 18:45:23 2010 on chan 1 [openr2 version 1.3.0, revision (release)][18:45:23:676] [Thread: 3058592656] [Chan 1] - Initialized R2 MF detector[18:45:23:676] [Thread: 3058592656] [Chan 1] - CAS Tx >> [SEIZE ACK] 0x0C[18:45:23:676] [Thread: 3058592656] [Chan 1] - CAS Raw Tx >> 0x0D[18:45:23:759] [Thread: 3058592656] [Chan 1] - MF Rx << 4 [ON][18:45:23:759] [Thread: 3058592656] [Chan 1] - Attempting to cancel timer timer 0[18:45:23:759] [Thread: 3058592656] [Chan 1] - Cannot cancel timer 0[18:45:23:759] [Thread: 3058592656] [Chan 1] - Getting DNIS digit 4[18:45:23:759] [Thread: 3058592656] [Chan 1] - DNIS so far: 4, expected length: 4[18:45:23:759] [Thread: 3058592656] [Chan 1] - Requesting next DNIS with signal 0x31.[18:45:23:759] [Thread: 3058592656] [Chan 1] - MF Tx >> 1 [ON][18:45:23:759] [Thread: 3058592656] [Chan 1] - scheduled timer id 2 (mf_back_cycle)[18:45:23:839] [Thread: 3058592656] [Chan 1] - MF Rx << 4 [OFF][18:45:23:839] [Thread: 3058592656] [Chan 1] - MF Tx >> 1 [OFF][18:45:23:899] [Thread: 3058592656] [Chan 1] - MF Rx << 8 [ON][18:45:23:899] [Thread: 3058592656] [Chan 1] - Attempting to cancel timer timer 2[18:45:23:899] [Thread: 3058592656] [Chan 1] - timer id 2 found, cancelling it now[18:45:23:899] [Thread: 3058592656] [Chan 1] - Getting DNIS digit 8[18:45:23:899] [Thread: 3058592656] [Chan 1] - DNIS so far: 48, expected length: 4[18:45:23:899] [Thread: 3058592656] [Chan 1] - Requesting next DNIS with signal 0x31.[18:45:23:899] [Thread: 3058592656] [Chan 1] - MF Tx >> 1 [ON][18:45:23:899] [Thread: 3058592656] [Chan 1] - scheduled timer id 3 (mf_back_cycle)[18:45:23:959] [Thread: 3058592656] [Chan 1] - MF Rx << 8 [OFF][18:45:23:959] [Thread: 3058592656] [Chan 1] - MF Tx >> 1 [OFF][18:45:24:039] [Thread: 3058592656] [Chan 1] - MF Rx << 1 [ON][18:45:24:039] [Thread: 3058592656] [Chan 1] - Attempting to cancel timer timer 3[18:45:24:039] [Thread: 3058592656] [Chan 1] - timer id 3 found, cancelling it now[18:45:24:039] [Thread: 3058592656] [Chan 1] - Getting DNIS digit 1[18:45:24:039] [Thread: 3058592656] [Chan 1] - DNIS so far: 481, expected length: 4[18:45:24:039] [Thread: 3058592656] [Chan 1] - Requesting next DNIS with signal 0x31.[18:45:24:039] [Thread: 3058592656] [Chan 1] - MF Tx >> 1 [ON][18:45:24:039] [Thread: 3058592656] [Chan 1] - scheduled timer id 4 (mf_back_cycle)[18:45:24:119] [Thread: 3058592656] [Chan 1] - MF Rx << 1 [OFF][18:45:24:119] [Thread: 3058592656] [Chan 1] - MF Tx >> 1 [OFF][18:45:24:179] [Thread: 3058592656] [Chan 1] - MF Rx << 8 [ON][18:45:24:179] [Thread: 3058592656] [Chan 1] - Attempting to cancel timer timer 4[18:45:24:179] [Thread: 3058592656] [Chan 1] - timer id 4 found, cancelling it now[18:45:24:179] [Thread: 3058592656] [Chan 1] - Getting DNIS digit 8[18:45:24:179] [Thread: 3058592656] [Chan 1] - DNIS so far: 4818, expected length: 4[18:45:24:179] [Thread: 3058592656] [Chan 1] - Done getting DNIS![18:45:24:179] [Thread: 3058592656] [Chan 1] - MF Tx >> 5 [ON][18:45:24:179] [Thread: 3058592656] [Chan 1] - scheduled timer id 5 (mf_back_cycle)[18:45:24:259] [Thread: 3058592656] [Chan 1] - MF Rx << 8 [OFF][18:45:24:259] [Thread: 3058592656] [Chan 1] - MF Tx >> 5 [OFF][18:45:24:339] [Thread: 3058592656] [Chan 1] - MF Rx << 1 [ON][18:45:24:339] [Thread: 3058592656] [Chan 1] - Attempting to cancel timer timer 5[18:45:24:339] [Thread: 3058592656] [Chan 1] - timer id 5 found, cancelling it now[18:45:24:339] [Thread: 3058592656] [Chan 1] - MF Tx >> 5 [ON][18:45:24:339] [Thread: 3058592656] [Chan 1] - scheduled timer id 6 (mf_back_cycle)[18:45:24:419] [Thread: 3058592656] [Chan 1] - MF Rx << 1 [OFF][18:45:24:419] [Thread: 3058592656] [Chan 1] - MF Tx >> 5 [OFF][18:45:24:479] [Thread: 3058592656] [Chan 1] - MF Rx << 1 [ON][18:45:24:479] [Thread: 3058592656] [Chan 1] - Attempting to cancel timer timer 6[18:45:24:479] [Thread: 3058592656] [Chan 1] - timer id 6 found, cancelling it now[18:45:24:479] [Thread: 3058592656] [Chan 1] - Getting ANI digit 1[18:45:24:479] [Thread: 3058592656] [Chan 1] - ANI so far: 1, expected length: 20[18:45:24:479] [Thread: 3058592656] [Chan 1] - MF Tx >> 5 [ON][18:45:24:479] [Thread: 3058592656] [Chan 1] - scheduled timer id 7 (mf_back_cycle)[18:45:24:559] [Thread: 3058592656] [Chan 1] - MF Rx << 1 [OFF][18:45:24:559] [Thread: 3058592656] [Chan 1] - MF Tx >> 5 [OFF][18:45:24:639] [Thread: 3058592656] [Chan 1] - MF Rx << 2 [ON][18:45:24:639] [Thread: 3058592656] [Chan 1] - Attempting to cancel timer timer 7[18:45:24:639] [Thread: 3058592656] [Chan 1] - timer id 7 found, cancelling it now[18:45:24:639] [Thread: 3058592656] [Chan 1] - Getting ANI digit 2[18:45:24:639] [Thread: 3058592656] [Chan 1] - ANI so far: 12, expected length: 20[18:45:24:639] [Thread: 3058592656] [Chan 1] - MF Tx >> 5 [ON][18:45:24:639] [Thread: 3058592656] [Chan 1] - scheduled timer id 8 (mf_back_cycle)[18:45:24:699] [Thread: 3058592656] [Chan 1] - MF Rx << 2 [OFF][18:45:24:699] [Thread: 3058592656] [Chan 1] - MF Tx >> 5 [OFF][18:45:24:759] [Thread: 3058592656] [Chan 1] - MF Rx << 3 [ON][18:45:24:759] [Thread: 3058592656] [Chan 1] - Attempting to cancel timer timer 8[18:45:24:759] [Thread: 3058592656] [Chan 1] - timer id 8 found, cancelling it now[18:45:24:759] [Thread: 3058592656] [Chan 1] - Getting ANI digit 3[18:45:24:759] [Thread: 3058592656] [Chan 1] - ANI so far: 123, expected length: 20[18:45:24:759] [Thread: 3058592656] [Chan 1] - MF Tx >> 5 [ON][18:45:24:759] [Thread: 3058592656] [Chan 1] - scheduled timer id 9 (mf_back_cycle)[18:45:24:839] [Thread: 3058592656] [Chan 1] - MF Rx << 3 [OFF][18:45:24:839] [Thread: 3058592656] [Chan 1] - MF Tx >> 5 [OFF][18:45:24:899] [Thread: 3058592656] [Chan 1] - MF Rx << 0 [ON][18:45:24:899] [Thread: 3058592656] [Chan 1] - Attempting to cancel timer timer 9[18:45:24:899] [Thread: 3058592656] [Chan 1] - timer id 9 found, cancelling it now[18:45:24:899] [Thread: 3058592656] [Chan 1] - Getting ANI digit 0[18:45:24:899] [Thread: 3058592656] [Chan 1] - ANI so far: 1230, expected length: 20[18:45:24:899] [Thread: 3058592656] [Chan 1] - MF Tx >> 5 [ON][18:45:24:899] [Thread: 3058592656] [Chan 1] - scheduled timer id 10 (mf_back_cycle)[18:45:24:959] [Thread: 3058592656] [Chan 1] - MF Rx << 0 [OFF][18:45:24:959] [Thread: 3058592656] [Chan 1] - MF Tx >> 5 [OFF][18:45:25:039] [Thread: 3058592656] [Chan 1] - MF Rx << 2 [ON][18:45:25:039] [Thread: 3058592656] [Chan 1] - Attempting to cancel timer timer 10[18:45:25:039] [Thread: 3058592656] [Chan 1] - timer id 10 found, cancelling it now[18:45:25:039] [Thread: 3058592656] [Chan 1] - Getting ANI digit 2[18:45:25:039] [Thread: 3058592656] [Chan 1] - ANI so far: 12302, expected length: 20[18:45:25:039] [Thread: 3058592656] [Chan 1] - MF Tx >> 5 [ON][18:45:25:039] [Thread: 3058592656] [Chan 1] - scheduled timer id 11 (mf_back_cycle)[18:45:25:119] [Thread: 3058592656] [Chan 1] - MF Rx << 2 [OFF][18:45:25:119] [Thread: 3058592656] [Chan 1] - MF Tx >> 5 [OFF][18:45:25:179] [Thread: 3058592656] [Chan 1] - MF Rx << 1 [ON][18:45:25:179] [Thread: 3058592656] [Chan 1] - Attempting to cancel timer timer 11[18:45:25:179] [Thread: 3058592656] [Chan 1] - timer id 11 found, cancelling it now[18:45:25:179] [Thread: 3058592656] [Chan 1] - Getting ANI digit 1[18:45:25:179] [Thread: 3058592656] [Chan 1] - ANI so far: 123021, expected length: 20[18:45:25:179] [Thread: 3058592656] [Chan 1] - MF Tx >> 5 [ON][18:45:25:179] [Thread: 3058592656] [Chan 1] - scheduled timer id 12 (mf_back_cycle)[18:45:25:239] [Thread: 3058592656] [Chan 1] - MF Rx << 1 [OFF][18:45:25:239] [Thread: 3058592656] [Chan 1] - MF Tx >> 5 [OFF][18:45:25:299] [Thread: 3058592656] [Chan 1] - MF Rx << 0 [ON][18:45:25:299] [Thread: 3058592656] [Chan 1] - Attempting to cancel timer timer 12[18:45:25:299] [Thread: 3058592656] [Chan 1] - timer id 12 found, cancelling it now[18:45:25:299] [Thread: 3058592656] [Chan 1] - Getting ANI digit 0[18:45:25:299] [Thread: 3058592656] [Chan 1] - ANI so far: 1230210, expected length: 20[18:45:25:299] [Thread: 3058592656] [Chan 1] - MF Tx >> 5 [ON][18:45:25:299] [Thread: 3058592656] [Chan 1] - scheduled timer id 13 (mf_back_cycle)[18:45:25:359] [Thread: 3058592656] [Chan 1] - MF Rx << 0 [OFF][18:45:25:359] [Thread: 3058592656] [Chan 1] - MF Tx >> 5 [OFF][18:45:25:439] [Thread: 3058592656] [Chan 1] - MF Rx << 5 [ON][18:45:25:439] [Thread: 3058592656] [Chan 1] - Attempting to cancel timer timer 13[18:45:25:439] [Thread: 3058592656] [Chan 1] - timer id 13 found, cancelling it now[18:45:25:439] [Thread: 3058592656] [Chan 1] - Getting ANI digit 5[18:45:25:439] [Thread: 3058592656] [Chan 1] - ANI so far: 12302105, expected length: 20[18:45:25:439] [Thread: 3058592656] [Chan 1] - MF Tx >> 5 [ON][18:45:25:439] [Thread: 3058592656] [Chan 1] - scheduled timer id 14 (mf_back_cycle)[18:45:25:519] [Thread: 3058592656] [Chan 1] - MF Rx << 5 [OFF][18:45:25:519] [Thread: 3058592656] [Chan 1] - MF Tx >> 5 [OFF][18:45:25:579] [Thread: 3058592656] [Chan 1] - MF Rx << 7 [ON][18:45:25:579] [Thread: 3058592656] [Chan 1] - Attempting to cancel timer timer 14[18:45:25:579] [Thread: 3058592656] [Chan 1] - timer id 14 found, cancelling it now[18:45:25:579] [Thread: 3058592656] [Chan 1] - Getting ANI digit 7[18:45:25:579] [Thread: 3058592656] [Chan 1] - ANI so far: 123021057, expected length: 20[18:45:25:579] [Thread: 3058592656] [Chan 1] - MF Tx >> 5 [ON][18:45:25:579] [Thread: 3058592656] [Chan 1] - scheduled timer id 15 (mf_back_cycle)[18:45:25:639] [Thread: 3058592656] [Chan 1] - MF Rx << 7 [OFF][18:45:25:639] [Thread: 3058592656] [Chan 1] - MF Tx >> 5 [OFF][18:45:25:719] [Thread: 3058592656] [Chan 1] - MF Rx << 3 [ON][18:45:25:719] [Thread: 3058592656] [Chan 1] - Attempting to cancel timer timer 15[18:45:25:719] [Thread: 3058592656] [Chan 1] - timer id 15 found, cancelling it now[18:45:25:719] [Thread: 3058592656] [Chan 1] - Getting ANI digit 3[18:45:25:719] [Thread: 3058592656] [Chan 1] - ANI so far: 1230210573, expected length: 20[18:45:25:719] [Thread: 3058592656] [Chan 1] - MF Tx >> 5 [ON][18:45:25:719] [Thread: 3058592656] [Chan 1] - scheduled timer id 16 (mf_back_cycle)[18:45:25:799] [Thread: 3058592656] [Chan 1] - MF Rx << 3 [OFF][18:45:25:799] [Thread: 3058592656] [Chan 1] - MF Tx >> 5 [OFF][18:45:25:859] [Thread: 3058592656] [Chan 1] - MF Rx << F [ON][18:45:25:859] [Thread: 3058592656] [Chan 1] - Attempting to cancel timer timer 16[18:45:25:859] [Thread: 3058592656] [Chan 1] - timer id 16 found, cancelling it now[18:45:25:859] [Thread: 3058592656] [Chan 1] - Got end of ANI[18:45:25:859] [Thread: 3058592656] [Chan 1] - By-passing B/II signals, accept the call with signal 0x0[18:45:25:859] [Thread: 3058592656] [Chan 1] - MF Tx >> 1 [ON][18:45:25:859] [Thread: 3058592656] [Chan 1] - scheduled timer id 17 (mf_back_cycle)[18:45:25:939] [Thread: 3058592656] [Chan 1] - MF Rx << F [OFF][18:45:25:939] [Thread: 3058592656] [Chan 1] - MF Tx >> 1 [OFF][18:45:25:939] [Thread: 3058592656] [Chan 1] - Attempting to cancel timer timer 17[18:45:25:939] [Thread: 3058592656] [Chan 1] - timer id 17 found, cancelling it now[18:45:25:939] [Thread: 3058592656] [Chan 1] - scheduled timer id 18 (r2_answer_delay)[18:45:26:099] [Thread: 3058592656] [Chan 1] - Attempting to cancel timer timer 18[18:45:26:099] [Thread: 3058592656] [Chan 1] - timer id 18 found, cancelling it now[18:45:26:099] [Thread: 3058592656] [Chan 1] - calling timer 18 (r2_answer_delay) callback[18:45:26:099] [Thread: 3050437520] [Chan 1] - CAS Tx >> [ANSWER] 0x04[18:45:26:099] [Thread: 3050437520] [Chan 1] - CAS Raw Tx >> 0x05[18:45:26:119] [Thread: 3050437520] [Chan 1] - Attempting to cancel timer timer 0[18:45:26:119] [Thread: 3050437520] [Chan 1] - Cannot cancel timer 0[18:45:26:119] [Thread: 3050437520] [Chan 1] - CAS Tx >> [CLEAR BACK] 0x0C[18:45:26:119] [Thread: 3050437520] [Chan 1] - CAS Raw Tx >> 0x0D[18:45:46:044] [Thread: 3058592656] [Chan 1] - Bits changed from 0x00 to 0x08[18:45:46:044] [Thread: 3058592656] [Chan 1] - CAS Rx << [CLEAR FORWARD] 0x08[18:45:46:044] [Thread: 3058592656] [Chan 1] - Call ended[18:45:46:044] [Thread: 3058592656] [Chan 1] - Attempting to cancel timer timer 0[18:45:46:044] [Thread: 3058592656] [Chan 1] - Cannot cancel timer 0

Thanks for any help!!!Att,

Flavio Roberto Miranda

MSN:flaviormiranda at hotmail.com
Skype: flaviormiranda

-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.digium.com/pipermail/asterisk-r2/attachments/20101129/aff39813/attachment-0001.htm 