[asterisk-r2] problemas con R2 con central NEC

Sun Sep 1 07:27:25 CDT 2013

Es lo que estuve haciendo pero en los logs (los archivos.call) que genera el debug no veo en ningun lado los milisegundos. Como hiciste para obtenerlos?Por lo que veo de tu explicacion lo que yo pretendía (hacer que falle 100% de las veces) no seria posible dado que todo depende de un comportamiento irregular de la NEC.Para lo cual me parece que deberia continuar las pruebas como al final estaba intentando, por ejemplo probar 30 llamadas (usando redial para no alterar el resultado con el marcado manual) y ver cuantas fallan de 30.Cuando lo corregiste te funcionaron el 100%  o algunas pocas aveces te fallaban tambien?Porque con algunos cambios del treshold pasaban de fallarme 15 o 18de 30 a fallar 3 o 4 de 30
saludos y gracias

> Message: 3
> Date: Fri, 30 Aug 2013 19:47:43 -0500
> From: Oscar Rocha <orochamty at hotmail.com>
> Subject: Re: [asterisk-r2] problemas con R2 con central NEC
> To: "asterisk-r2 at lists.digium.com" <asterisk-r2 at lists.digium.com>
> Message-ID: <BLU180-W28815965147B09F5B4B66B7360 at phx.gbl>
> Content-Type: text/plain; charset="iso-8859-1"
> 
> Qu? tal Marcelo, tienes que hacer un poco de investigaci?n en los logs para poder determinar el tiempo en el mf_threshold que requieres para que funcione, lo que yo hice fue analizar llamadas en las que yo sab?a qu? n?mero era el que deber?a marcarse, busqu? en el log del R2 la llamada de acuerdo al canal y tuve que tomar el tiempo en mseg entre cada d?gito recibido, promedio entre d?gitos era de 180-200 mseg pero hab?a ocasiones que llegaba a ser hasta de 120 mseg. Cuando un n?mero era "repetido" regularmente el tiempo entre el d?gito anterior y este repetido era muy bajo, en mi caso era desde 40 a 80 mseg, por eso el mf_threshold lo puse en 90 para evitar esos d?gitos repetidos pero no descartar alguno que fuera v?lido y que tuviera un tiempo bajo como 100 mseg.
> 
> Como ejemplo te pongo el log de una llamada obtenida a partir del archivo de debug del R2:
> 
> [17:51:50:796] [Thread: 3073014672] [Chan 5] - Call started at Wed Jun 26 17:51:50 2013 on chan 5 [openr2 version 1.3.1, revision exported]
> [17:51:50:796] [Thread: 3073014672] [Chan 5] - Initialized R2 MF detector
> [17:51:50:796] [Thread: 3073014672] [Chan 5] - CAS Tx >> [SEIZE ACK] 0x0C
> [17:51:50:796] [Thread: 3073014672] [Chan 5] - CAS Raw Tx >> 0x0D
> --> [17:51:51:487] [Thread: 3073014672] [Chan 5] - MF Rx << 0 [ON]
> [17:51:51:487] [Thread: 3073014672] [Chan 5] - Attempting to cancel timer timer 0
> [17:51:51:487] [Thread: 3073014672] [Chan 5] - Cannot cancel timer 0
> [17:51:51:487] [Thread: 3073014672] [Chan 5] - Getting DNIS digit 0
> [17:51:51:487] [Thread: 3073014672] [Chan 5] - DNIS so far: 0, expected length: 13
> [17:51:51:487] [Thread: 3073014672] [Chan 5] - Requesting next DNIS with signal 0x31.
> [17:51:51:487] [Thread: 3073014672] [Chan 5] - MF Tx >> 1 [ON]
> [17:51:51:487] [Thread: 3073014672] [Chan 5] - scheduled timer id 2 (mf_back_cycle)
> [17:51:51:587] [Thread: 3073014672] [Chan 5] - MF Rx << 0 [OFF]
> [17:51:51:587] [Thread: 3073014672] [Chan 5] - MF Tx >> 1 [OFF]
> --> [17:51:51:687] [Thread: 3073014672] [Chan 5] - MF Rx << 1 [ON]
> [17:51:51:687] [Thread: 3073014672] [Chan 5] - Attempting to cancel timer timer 2
> [17:51:51:687] [Thread: 3073014672] [Chan 5] - timer id 2 found, cancelling it now
> [17:51:51:687] [Thread: 3073014672] [Chan 5] - Getting DNIS digit 1
> [17:51:51:687] [Thread: 3073014672] [Chan 5] - DNIS so far: 01, expected length: 13
> [17:51:51:687] [Thread: 3073014672] [Chan 5] - Requesting next DNIS with signal 0x31.
> [17:51:51:687] [Thread: 3073014672] [Chan 5] - MF Tx >> 1 [ON]
> [17:51:51:687] [Thread: 3073014672] [Chan 5] - scheduled timer id 3 (mf_back_cycle)
> [17:51:51:767] [Thread: 3073014672] [Chan 5] - MF Rx << 1 [OFF]
> [17:51:51:767] [Thread: 3073014672] [Chan 5] - MF Tx >> 1 [OFF]
> --> [17:51:51:867] [Thread: 3073014672] [Chan 5] - MF Rx << 7 [ON]
> [17:51:51:867] [Thread: 3073014672] [Chan 5] - Attempting to cancel timer timer 3
> [17:51:51:867] [Thread: 3073014672] [Chan 5] - timer id 3 found, cancelling it now
> [17:51:51:867] [Thread: 3073014672] [Chan 5] - Getting DNIS digit 7
> [17:51:51:867] [Thread: 3073014672] [Chan 5] - DNIS so far: 017, expected length: 13
> [17:51:51:867] [Thread: 3073014672] [Chan 5] - Requesting next DNIS with signal 0x31.
> [17:51:51:867] [Thread: 3073014672] [Chan 5] - MF Tx >> 1 [ON]
> [17:51:51:867] [Thread: 3073014672] [Chan 5] - scheduled timer id 4 (mf_back_cycle)
> [17:51:51:947] [Thread: 3073014672] [Chan 5] - MF Rx << 7 [OFF]
> [17:51:51:947] [Thread: 3073014672] [Chan 5] - MF Tx >> 1 [OFF]
> --> [17:51:52:047] [Thread: 3073014672] [Chan 5] - MF Rx << 7 [ON]
> [17:51:52:047] [Thread: 3073014672] [Chan 5] - Attempting to cancel timer timer 4
> [17:51:52:047] [Thread: 3073014672] [Chan 5] - timer id 4 found, cancelling it now
> [17:51:52:047] [Thread: 3073014672] [Chan 5] - Getting DNIS digit 7
> [17:51:52:047] [Thread: 3073014672] [Chan 5] - DNIS so far: 0177, expected length: 13
> [17:51:52:047] [Thread: 3073014672] [Chan 5] - Requesting next DNIS with signal 0x31.
> [17:51:52:047] [Thread: 3073014672] [Chan 5] - MF Tx >> 1 [ON]
> [17:51:52:047] [Thread: 3073014672] [Chan 5] - scheduled timer id 5 (mf_back_cycle)
> [17:51:52:147] [Thread: 3073014672] [Chan 5] - MF Rx << 7 [OFF]
> [17:51:52:147] [Thread: 3073014672] [Chan 5] - MF Tx >> 1 [OFF]
> --> [17:51:52:247] [Thread: 3073014672] [Chan 5] - MF Rx << 9 [ON]
> [17:51:52:247] [Thread: 3073014672] [Chan 5] - Attempting to cancel timer timer 5
> [17:51:52:247] [Thread: 3073014672] [Chan 5] - timer id 5 found, cancelling it now
> [17:51:52:247] [Thread: 3073014672] [Chan 5] - Getting DNIS digit 9
> [17:51:52:247] [Thread: 3073014672] [Chan 5] - DNIS so far: 01779, expected length: 13
> [17:51:52:247] [Thread: 3073014672] [Chan 5] - Requesting next DNIS with signal 0x31.
> [17:51:52:247] [Thread: 3073014672] [Chan 5] - MF Tx >> 1 [ON]
> [17:51:52:247] [Thread: 3073014672] [Chan 5] - scheduled timer id 6 (mf_back_cycle)
> [17:51:52:327] [Thread: 3073014672] [Chan 5] - MF Rx << 9 [OFF]
> [17:51:52:327] [Thread: 3073014672] [Chan 5] - MF Tx >> 1 [OFF]
> --> [17:51:52:427] [Thread: 3073014672] [Chan 5] - MF Rx << 7 [ON]
> [17:51:52:427] [Thread: 3073014672] [Chan 5] - Attempting to cancel timer timer 6
> [17:51:52:427] [Thread: 3073014672] [Chan 5] - timer id 6 found, cancelling it now
> [17:51:52:427] [Thread: 3073014672] [Chan 5] - Getting DNIS digit 7
> [17:51:52:427] [Thread: 3073014672] [Chan 5] - DNIS so far: 017797, expected length: 13
> [17:51:52:427] [Thread: 3073014672] [Chan 5] - Requesting next DNIS with signal 0x31.
> [17:51:52:427] [Thread: 3073014672] [Chan 5] - MF Tx >> 1 [ON]
> [17:51:52:427] [Thread: 3073014672] [Chan 5] - scheduled timer id 7 (mf_back_cycle)
> [17:51:52:527] [Thread: 3073014672] [Chan 5] - MF Rx << 7 [OFF]
> [17:51:52:527] [Thread: 3073014672] [Chan 5] - MF Tx >> 1 [OFF]
> --> [17:51:52:627] [Thread: 3073014672] [Chan 5] - MF Rx << 9 [ON]
> [17:51:52:627] [Thread: 3073014672] [Chan 5] - Attempting to cancel timer timer 7
> [17:51:52:627] [Thread: 3073014672] [Chan 5] - timer id 7 found, cancelling it now
> [17:51:52:627] [Thread: 3073014672] [Chan 5] - Getting DNIS digit 9
> [17:51:52:627] [Thread: 3073014672] [Chan 5] - DNIS so far: 0177979, expected length: 13
> [17:51:52:627] [Thread: 3073014672] [Chan 5] - Requesting next DNIS with signal 0x31.
> [17:51:52:627] [Thread: 3073014672] [Chan 5] - MF Tx >> 1 [ON]
> [17:51:52:627] [Thread: 3073014672] [Chan 5] - scheduled timer id 8 (mf_back_cycle)
> [17:51:52:707] [Thread: 3073014672] [Chan 5] - MF Rx << 9 [OFF]
> [17:51:52:707] [Thread: 3073014672] [Chan 5] - MF Tx >> 1 [OFF]
> --> [17:51:52:807] [Thread: 3073014672] [Chan 5] - MF Rx << 6 [ON]
> [17:51:52:807] [Thread: 3073014672] [Chan 5] - Attempting to cancel timer timer 8
> [17:51:52:807] [Thread: 3073014672] [Chan 5] - timer id 8 found, cancelling it now
> [17:51:52:807] [Thread: 3073014672] [Chan 5] - Getting DNIS digit 6
> [17:51:52:807] [Thread: 3073014672] [Chan 5] - DNIS so far: 01779796, expected length: 13
> [17:51:52:807] [Thread: 3073014672] [Chan 5] - Requesting next DNIS with signal 0x31.
> [17:51:52:807] [Thread: 3073014672] [Chan 5] - MF Tx >> 1 [ON]
> [17:51:52:807] [Thread: 3073014672] [Chan 5] - scheduled timer id 9 (mf_back_cycle)
> [17:51:52:887] [Thread: 3073014672] [Chan 5] - MF Rx << 6 [OFF]
> [17:51:52:887] [Thread: 3073014672] [Chan 5] - MF Tx >> 1 [OFF]
> --> [17:51:52:967] [Thread: 3073014672] [Chan 5] - MF Rx << 9 [ON]
> [17:51:52:967] [Thread: 3073014672] [Chan 5] - Attempting to cancel timer timer 9
> [17:51:52:967] [Thread: 3073014672] [Chan 5] - timer id 9 found, cancelling it now
> [17:51:52:967] [Thread: 3073014672] [Chan 5] - Getting DNIS digit 9
> [17:51:52:967] [Thread: 3073014672] [Chan 5] - DNIS so far: 017797969, expected length: 13
> [17:51:52:967] [Thread: 3073014672] [Chan 5] - Requesting next DNIS with signal 0x31.
> [17:51:52:967] [Thread: 3073014672] [Chan 5] - MF Tx >> 1 [ON]
> [17:51:52:967] [Thread: 3073014672] [Chan 5] - scheduled timer id 10 (mf_back_cycle)
> [17:51:52:987] [Thread: 3073014672] [Chan 5] - MF Rx << 9 [OFF]
> [17:51:52:987] [Thread: 3073014672] [Chan 5] - MF Tx >> 1 [OFF]
> -->--> [17:51:53:007] [Thread: 3073014672] [Chan 5] - MF Rx << 9 [ON]
> [17:51:53:007] [Thread: 3073014672] [Chan 5] - Attempting to cancel timer timer 10
> [17:51:53:007] [Thread: 3073014672] [Chan 5] - timer id 10 found, cancelling it now
> [17:51:53:007] [Thread: 3073014672] [Chan 5] - Getting DNIS digit 9
> [17:51:53:007] [Thread: 3073014672] [Chan 5] - DNIS so far: 0177979699, expected length: 13
> [17:51:53:007] [Thread: 3073014672] [Chan 5] - Requesting next DNIS with signal 0x31.
> [17:51:53:007] [Thread: 3073014672] [Chan 5] - MF Tx >> 1 [ON]
> [17:51:53:007] [Thread: 3073014672] [Chan 5] - scheduled timer id 11 (mf_back_cycle)
> [17:51:53:087] [Thread: 3073014672] [Chan 5] - MF Rx << 9 [OFF]
> [17:51:53:087] [Thread: 3073014672] [Chan 5] - MF Tx >> 1 [OFF]
> --> [17:51:53:187] [Thread: 3073014672] [Chan 5] - MF Rx << 2 [ON]
> [17:51:53:187] [Thread: 3073014672] [Chan 5] - Attempting to cancel timer timer 11
> [17:51:53:187] [Thread: 3073014672] [Chan 5] - timer id 11 found, cancelling it now
> [17:51:53:187] [Thread: 3073014672] [Chan 5] - Getting DNIS digit 2
> [17:51:53:187] [Thread: 3073014672] [Chan 5] - DNIS so far: 01779796992, expected length: 13
> [17:51:53:187] [Thread: 3073014672] [Chan 5] - Requesting next DNIS with signal 0x31.
> [17:51:53:187] [Thread: 3073014672] [Chan 5] - MF Tx >> 1 [ON]
> [17:51:53:187] [Thread: 3073014672] [Chan 5] - scheduled timer id 12 (mf_back_cycle)
> [17:51:53:247] [Thread: 3073014672] [Chan 5] - MF Rx << 2 [OFF]
> [17:51:53:247] [Thread: 3073014672] [Chan 5] - MF Tx >> 1 [OFF]
> --> [17:51:53:347] [Thread: 3073014672] [Chan 5] - MF Rx << 2 [ON]
> [17:51:53:347] [Thread: 3073014672] [Chan 5] - Attempting to cancel timer timer 12
> [17:51:53:347] [Thread: 3073014672] [Chan 5] - timer id 12 found, cancelling it now
> [17:51:53:347] [Thread: 3073014672] [Chan 5] - Getting DNIS digit 2
> [17:51:53:347] [Thread: 3073014672] [Chan 5] - DNIS so far: 017797969922, expected length: 13
> [17:51:53:347] [Thread: 3073014672] [Chan 5] - User requested us to stop getting DNIS!
> [17:51:53:347] [Thread: 3073014672] [Chan 5] - MF Tx >> 6 [ON]
> [17:51:53:347] [Thread: 3073014672] [Chan 5] - scheduled timer id 13 (mf_back_cycle)
> [17:51:53:427] [Thread: 3073014672] [Chan 5] - MF Rx << 2 [OFF]
> [17:51:53:427] [Thread: 3073014672] [Chan 5] - MF Tx >> 6 [OFF]
> --> [17:51:53:527] [Thread: 3073014672] [Chan 5] - MF Rx << 2 [ON]
> [17:51:53:527] [Thread: 3073014672] [Chan 5] - Attempting to cancel timer timer 13
> [17:51:53:527] [Thread: 3073014672] [Chan 5] - timer id 13 found, cancelling it now
> [17:51:53:527] [Thread: 3073014672] [Chan 5] - MF Tx >> 1 [ON]
> [17:51:53:527] [Thread: 3073014672] [Chan 5] - scheduled timer id 14 (mf_back_cycle)
> [17:51:53:627] [Thread: 3073014672] [Chan 5] - MF Rx << 2 [OFF]
> [17:51:53:627] [Thread: 3073014672] [Chan 5] - MF Tx >> 1 [OFF]
> --> [17:51:53:747] [Thread: 3073014672] [Chan 5] - MF Rx << F [ON]
> [17:51:53:747] [Thread: 3073014672] [Chan 5] - Attempting to cancel timer timer 14
> [17:51:53:747] [Thread: 3073014672] [Chan 5] - timer id 14 found, cancelling it now
> [17:51:53:747] [Thread: 3073014672] [Chan 5] - Got end of ANI
> [17:51:53:747] [Thread: 3073014672] [Chan 5] - Requesting change to Group II with signal 0x33
> [17:51:53:747] [Thread: 3073014672] [Chan 5] - MF Tx >> 3 [ON]
> [17:51:53:747] [Thread: 3073014672] [Chan 5] - scheduled timer id 15 (mf_back_cycle)
> [17:51:53:847] [Thread: 3073014672] [Chan 5] - MF Rx << F [OFF]
> [17:51:53:847] [Thread: 3073014672] [Chan 5] - MF Tx >> 3 [OFF]
> [17:51:53:947] [Thread: 3073014672] [Chan 5] - MF Rx << 2 [ON]
> [17:51:53:947] [Thread: 3073014672] [Chan 5] - Attempting to cancel timer timer 15
> [17:51:53:947] [Thread: 3073014672] [Chan 5] - timer id 15 found, cancelling it now
> [17:51:53:947] [Thread: 3073014672] [Chan 5] - MF Tx >> 1 [ON]
> [17:51:53:947] [Thread: 3073014672] [Chan 5] - scheduled timer id 16 (mf_back_cycle)
> [17:51:54:047] [Thread: 3073014672] [Chan 5] - MF Rx << 2 [OFF]
> [17:51:54:047] [Thread: 3073014672] [Chan 5] - MF Tx >> 1 [OFF]
> [17:51:54:047] [Thread: 3073014672] [Chan 5] - Attempting to cancel timer timer 16
> [17:51:54:047] [Thread: 3073014672] [Chan 5] - timer id 16 found, cancelling it now
> [17:51:54:047] [Thread: 3073014672] [Chan 5] - scheduled timer id 17 (r2_answer_delay)
> [17:51:54:207] [Thread: 3073014672] [Chan 5] - Attempting to cancel timer timer 17
> [17:51:54:207] [Thread: 3073014672] [Chan 5] - timer id 17 found, cancelling it now
> [17:51:54:207] [Thread: 3073014672] [Chan 5] - calling timer 17 (r2_answer_delay) callback
> [17:52:04:222] [Thread: 3068345232] [Chan 5] - CAS Tx >> [ANSWER] 0x04
> [17:52:04:222] [Thread: 3068345232] [Chan 5] - CAS Raw Tx >> 0x05
> [17:52:22:731] [Thread: 3068345232] [Chan 5] - Bits changed from 0x00 to 0x08
> [17:52:22:731] [Thread: 3068345232] [Chan 5] - CAS Rx << [CLEAR FORWARD] 0x08
> [17:52:22:731] [Thread: 3068345232] [Chan 5] - Far end disconnected. Reason: Normal Clearing
> [17:52:22:750] [Thread: 3068345232] [Chan 5] - Call ended
> [17:52:22:750] [Thread: 3068345232] [Chan 5] - Attempting to cancel timer timer 0
> [17:52:22:750] [Thread: 3068345232] [Chan 5] - Cannot cancel timer 0
> 
> Las l?neas con flechas indican cu?ndo un nuevo d?gito es recibido, entonces tomendo como referencia esto, tenemos lo siguiente:
> 
> N?mero: 017797969922
> 0 -> 1   200ms
> 1 -> 7   180ms
> 7 -> 7   180ms
> 7 -> 9   200ms
> 9 -> 7   180ms
> 7 -> 9   200ms
> 9 -> 6   180ms
> 6 -> 9   180ms
> 9 -> 9   40ms   ---->   D?gito repetido
> 9 -> 2   180ms
> 2 -> 2   160ms
> 
> Tienes que analizar varias llamadas para poder determinar el tiempo correcto.
> 
> Espero te sirva esta descripci?n.
> 
> Oscar Rocha.
> 
> 
> 
> From: marceloeduardo12345678 at hotmail.com
> To: asterisk-r2 at lists.digium.com
> Date: Fri, 30 Aug 2013 21:01:38 +0000
> Subject: [asterisk-r2] problemas con R2 con central NEC
> 
> 
> 
> 
> Hola, los molesto con la siguiente consulta.Tengo una elastix 2.4 conectada a una central NEC a traves de una E1 por R2 y tengo un problema similar al descripto en:http://lists.digium.com/pipermail/asterisk-r2/2013-July/002931.htmlTanto con el ANI como con el DNIS sucede que a veces (muy frecuentemente) elastix recibe d?gitos repetidos.Por ejemplo en NEC tengo el 2500 que llama al 5288 del elastix.Respecto al ANI a veces llega 5228 o 5528 de manera que se interpreta en forma repetida un d?gito y luego se trunca al llegar a los 4 digitos totales dando el marcado err?neo.Tambien sucede con el DNIS solo que all? obviamente el numero no es truncado, llega 25000 o 22500 por ejemplo.Habilitando el debug no hay nada anormal, la secuencia se completa perfectamente como si el numero marcado fuera efectivamente el erroneo cuando en realidad no es as?.
> He intentado implementar la solucion descripta en:http://lists.digium.com/pipermail/asterisk-r2/2013-July/002939.htmlModificando el mf_threshold sin lograr solucionarlo.De hecho he tratado de "forzar" el fallo para que ocurra en el 100% de los casos para confirmar si el problema es ese pero ponga el valor que ponga en mf_threshold el fallo es igual, falla la mitad de las veces mas o menos (5 de 10), a veces mas, a veces menos.mf_threshold lo he puesto en 9, en 90, en 900, en 9000 y es lo mismo.
> Tambien he modificado el resto de los timers del r2proto.conf uno por uno en mas y en menos (multiplicado por 10 o dividiendo por 10) sin ?xito.Es decir si el valor es 8000 una prueba es 80000 la otra 800.
> # 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=10000
> timers.r2_seize=8000
> timers.r2_answer=80000
> timers.r2_metering_pulse=0
> timers.r2_double_answer=400
> timers.r2_answer_delay=150
> timers.cas_persistence_check=500
> timers.dtmf_start_dial=100
> 
> 
> ## misc settings ##
> 
> # time that a MF tone should persist before handling it
> mf_threshold=90
> 
> No puedo solucionar el problema y tampoco puedo tocar un par?metro que me de fallo 100% de los intentos como para confirmar que esto sea as?.
> Adjunto link de descarga con los logs de varios ejemplos, en todos los casos el 2500 de NEC llama al 5288 de elastix.Archivos .call con error de ANI y error de DNIS descriptos en el nimbre mismo del archivo.https://www.hightail.com/download/bWJwZ295eFVRWUs5TE1UQw
> Desde ya muy agradecido por el tiempo dispensado.
>  		 	   		  
> 
> --

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.digium.com/pipermail/asterisk-r2/attachments/20130901/ba8d9293/attachment-0001.htm>