[asterisk-r2] Call drops afret 50 sec or so...

Fri Feb 11 18:44:40 CST 2011

     I have a customer using Alestra for E1 service in Mexico City.  Lately
they are complaining that calls are dropping after 50 seconds or so.  Alestra
claims that Asterisk is dropping the call so I need to find out what could be
the cause.  Here is the log from a dropped call:

[15:27:14:392] [Thread: 110558096] [Chan 4] - Call started at Fri Feb 11
15:27:14 2011 on chan 4 [openr2 version 1.3.0, revision exported]
[15:27:14:392] [Thread: 110558096] [Chan 4] - Outgoing call proceeding:
ANI=3205, DNIS=25813311, Category=National Priority Subscriber
[15:27:14:392] [Thread: 110558096] [Chan 4] - CAS Tx >> [SEIZE] 0x00
[15:27:14:392] [Thread: 110558096] [Chan 4] - CAS Raw Tx >> 0x01
[15:27:14:392] [Thread: 110558096] [Chan 4] - scheduled timer id 2 (r2_seize)
[15:27:14:426] [Thread: 110558096] [Chan 4] - Bits changed from 0x08 to 0x0C
[15:27:14:426] [Thread: 110558096] [Chan 4] - CAS Rx << [SEIZE ACK] 0x0C
[15:27:14:426] [Thread: 110558096] [Chan 4] - Attempting to cancel timer timer 2
[15:27:14:426] [Thread: 110558096] [Chan 4] - timer id 2 found, cancelling it now
[15:27:14:426] [Thread: 110558096] [Chan 4] - MFC/R2 call acknowledge!
[15:27:14:426] [Thread: 110558096] [Chan 4] - Sending DNIS digit 2
[15:27:14:426] [Thread: 110558096] [Chan 4] - MF Tx >> 2 [ON]
[15:27:14:511] [Thread: 110558096] [Chan 4] - MF Rx << 1 [ON]
[15:27:14:511] [Thread: 110558096] [Chan 4] - Attempting to cancel timer timer 0
[15:27:14:511] [Thread: 110558096] [Chan 4] - Cannot cancel timer 0
[15:27:14:511] [Thread: 110558096] [Chan 4] - MF Tx >> 2 [OFF]
[15:27:14:571] [Thread: 110558096] [Chan 4] - MF Rx << 1 [OFF]
[15:27:14:571] [Thread: 110558096] [Chan 4] - Sending DNIS digit 5
[15:27:14:571] [Thread: 110558096] [Chan 4] - MF Tx >> 5 [ON]
[15:27:14:571] [Thread: 110558096] [Chan 4] - Group A DNIS request handled
[15:27:14:631] [Thread: 110558096] [Chan 4] - MF Rx << 1 [ON]
[15:27:14:631] [Thread: 110558096] [Chan 4] - Attempting to cancel timer timer 0
[15:27:14:631] [Thread: 110558096] [Chan 4] - Cannot cancel timer 0
[15:27:14:631] [Thread: 110558096] [Chan 4] - MF Tx >> 5 [OFF]
[15:27:14:691] [Thread: 110558096] [Chan 4] - MF Rx << 1 [OFF]
[15:27:14:691] [Thread: 110558096] [Chan 4] - Sending DNIS digit 8
[15:27:14:691] [Thread: 110558096] [Chan 4] - MF Tx >> 8 [ON]
[15:27:14:691] [Thread: 110558096] [Chan 4] - Group A DNIS request handled
[15:27:14:751] [Thread: 110558096] [Chan 4] - MF Rx << 1 [ON]
[15:27:14:751] [Thread: 110558096] [Chan 4] - Attempting to cancel timer timer 0
[15:27:14:751] [Thread: 110558096] [Chan 4] - Cannot cancel timer 0
[15:27:14:751] [Thread: 110558096] [Chan 4] - MF Tx >> 8 [OFF]
[15:27:14:811] [Thread: 110558096] [Chan 4] - MF Rx << 1 [OFF]
[15:27:14:811] [Thread: 110558096] [Chan 4] - Sending DNIS digit 1
[15:27:14:811] [Thread: 110558096] [Chan 4] - MF Tx >> 1 [ON]
[15:27:14:811] [Thread: 110558096] [Chan 4] - Group A DNIS request handled
[15:27:14:891] [Thread: 110558096] [Chan 4] - MF Rx << 1 [ON]
[15:27:14:891] [Thread: 110558096] [Chan 4] - Attempting to cancel timer timer 0
[15:27:14:891] [Thread: 110558096] [Chan 4] - Cannot cancel timer 0
[15:27:14:891] [Thread: 110558096] [Chan 4] - MF Tx >> 1 [OFF]
[15:27:14:951] [Thread: 110558096] [Chan 4] - MF Rx << 1 [OFF]
[15:27:14:951] [Thread: 110558096] [Chan 4] - Sending DNIS digit 3
[15:27:14:951] [Thread: 110558096] [Chan 4] - MF Tx >> 3 [ON]
[15:27:14:951] [Thread: 110558096] [Chan 4] - Group A DNIS request handled
[15:27:15:011] [Thread: 110558096] [Chan 4] - MF Rx << 1 [ON]
[15:27:15:011] [Thread: 110558096] [Chan 4] - Attempting to cancel timer timer 0
[15:27:15:011] [Thread: 110558096] [Chan 4] - Cannot cancel timer 0
[15:27:15:011] [Thread: 110558096] [Chan 4] - MF Tx >> 3 [OFF]
[15:27:15:071] [Thread: 110558096] [Chan 4] - MF Rx << 1 [OFF]
[15:27:15:071] [Thread: 110558096] [Chan 4] - Sending DNIS digit 3
[15:27:15:071] [Thread: 110558096] [Chan 4] - MF Tx >> 3 [ON]
[15:27:15:071] [Thread: 110558096] [Chan 4] - Group A DNIS request handled
[15:27:15:131] [Thread: 110558096] [Chan 4] - MF Rx << 1 [ON]
[15:27:15:131] [Thread: 110558096] [Chan 4] - Attempting to cancel timer timer 0
[15:27:15:131] [Thread: 110558096] [Chan 4] - Cannot cancel timer 0
[15:27:15:131] [Thread: 110558096] [Chan 4] - MF Tx >> 3 [OFF]
[15:27:15:191] [Thread: 110558096] [Chan 4] - MF Rx << 1 [OFF]
[15:27:15:191] [Thread: 110558096] [Chan 4] - Sending DNIS digit 1
[15:27:15:191] [Thread: 110558096] [Chan 4] - MF Tx >> 1 [ON]
[15:27:15:191] [Thread: 110558096] [Chan 4] - Group A DNIS request handled
[15:27:15:271] [Thread: 110558096] [Chan 4] - MF Rx << 1 [ON]
[15:27:15:271] [Thread: 110558096] [Chan 4] - Attempting to cancel timer timer 0
[15:27:15:271] [Thread: 110558096] [Chan 4] - Cannot cancel timer 0
[15:27:15:271] [Thread: 110558096] [Chan 4] - MF Tx >> 1 [OFF]
[15:27:15:331] [Thread: 110558096] [Chan 4] - MF Rx << 1 [OFF]
[15:27:15:331] [Thread: 110558096] [Chan 4] - Sending DNIS digit 1
[15:27:15:331] [Thread: 110558096] [Chan 4] - MF Tx >> 1 [ON]
[15:27:15:331] [Thread: 110558096] [Chan 4] - Group A DNIS request handled
[15:27:15:411] [Thread: 110558096] [Chan 4] - MF Rx << 1 [ON]
[15:27:15:411] [Thread: 110558096] [Chan 4] - Attempting to cancel timer timer 0
[15:27:15:411] [Thread: 110558096] [Chan 4] - Cannot cancel timer 0
[15:27:15:411] [Thread: 110558096] [Chan 4] - MF Tx >> 1 [OFF]
[15:27:15:471] [Thread: 110558096] [Chan 4] - MF Rx << 1 [OFF]
[15:27:15:471] [Thread: 110558096] [Chan 4] - No more DNIS. Doing nothing,
waiting for timeout.
[15:27:15:471] [Thread: 110558096] [Chan 4] - scheduled timer id 3 (mf_fwd_safety)
[15:27:15:471] [Thread: 110558096] [Chan 4] - Group A DNIS request handled
[15:27:18:411] [Thread: 110558096] [Chan 4] - MF Rx << 3 [ON]
[15:27:18:411] [Thread: 110558096] [Chan 4] - Attempting to cancel timer timer 3
[15:27:18:411] [Thread: 110558096] [Chan 4] - timer id 3 found, cancelling it now
[15:27:18:551] [Thread: 110558096] [Chan 4] - MF Rx << 3 [OFF]
[15:27:18:551] [Thread: 110558096] [Chan 4] - Sending category National
Priority Subscriber
[15:27:18:551] [Thread: 110558096] [Chan 4] - MF Tx >> 2 [ON]
[15:27:18:791] [Thread: 110558096] [Chan 4] - MF Rx << 1 [ON]
[15:27:18:791] [Thread: 110558096] [Chan 4] - Attempting to cancel timer timer 0
[15:27:18:791] [Thread: 110558096] [Chan 4] - Cannot cancel timer 0
[15:27:18:791] [Thread: 110558096] [Chan 4] - MF Tx >> 2 [OFF]
[15:27:18:851] [Thread: 110558096] [Chan 4] - MF Rx << 1 [OFF]
[15:27:18:851] [Thread: 110558096] [Chan 4] - scheduled timer id 4 (r2_answer)
[15:27:25:646] [Thread: 110558096] [Chan 4] - Bits changed from 0x0C to 0x04
[15:27:25:646] [Thread: 110558096] [Chan 4] - CAS Rx << [ANSWER] 0x04
[15:27:25:646] [Thread: 110558096] [Chan 4] - Attempting to cancel timer timer 4
[15:27:25:646] [Thread: 110558096] [Chan 4] - timer id 4 found, cancelling it now
[15:27:25:646] [Thread: 110558096] [Chan 4] - Attempting to cancel timer timer 0
[15:27:25:646] [Thread: 110558096] [Chan 4] - Cannot cancel timer 0
[15:28:11:265] [Thread: 110558096] [Chan 4] - Attempting to cancel timer timer 0
[15:28:11:265] [Thread: 110558096] [Chan 4] - Cannot cancel timer 0
[15:28:11:265] [Thread: 110558096] [Chan 4] - CAS Tx >> [CLEAR FORWARD] 0x08
[15:28:11:265] [Thread: 110558096] [Chan 4] - CAS Raw Tx >> 0x09
[15:28:11:296] [Thread: 118954896] [Chan 4] - Bits changed from 0x04 to 0x08
[15:28:11:296] [Thread: 118954896] [Chan 4] - CAS Rx << [IDLE] 0x08
[15:28:11:296] [Thread: 118954896] [Chan 4] - Call ended
[15:28:11:296] [Thread: 118954896] [Chan 4] - Attempting to cancel timer timer 0
[15:28:11:296] [Thread: 118954896] [Chan 4] - Cannot cancel timer 0

--
Carlos Chavez
Director de Tecnología
Telecomunicaciones Abiertas de México S.A. de C.V.
Tel: +52-55-91169161 Ext 2001