Here is a log when the call drops in Phase D after having received 4 pages! I am seeing this for the first time that call is dropping in Phase D. I think I could fix this, if someone could throw a pointer or two my way. Should I look into mod_spandsp_fax.c or can this be done elsewhere? f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:52.024887 [DEBUG] mod_spandsp_fax.c:428 ==== Page Received =========================================================== f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:52.024887 [DEBUG] mod_spandsp_fax.c:429 Page no = 4 f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:52.024887 [DEBUG] mod_spandsp_fax.c:430 Image size = 1728 x 999 pixels f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:52.024887 [DEBUG] mod_spandsp_fax.c:431 Image resolution = 8031/m x 3850/m f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:52.024887 [DEBUG] mod_spandsp_fax.c:432 Compression = T.6 (3) f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:52.024887 [DEBUG] mod_spandsp_fax.c:433 Compressed image size = 22935 bytes f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:52.024887 [DEBUG] mod_spandsp_fax.c:434 Bad rows = 0 f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:52.024887 [DEBUG] mod_spandsp_fax.c:435 Longest bad row run = 0 f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:52.024887 [DEBUG] mod_spandsp_fax.c:436 ============================================================================== 2012-03-26 22:02:52.024887 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Changing from state 13 to 14 2012-03-26 22:02:52.024887 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Tx: MCF with final frame tag 2012-03-26 22:02:52.024887 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Tx: ff 13 8c 2012-03-26 22:02:52.084891 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 HDLC signal status is Carrier down (-1) in state 14 2012-03-26 22:02:52.084891 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Changing from phase T30_PHASE_D_RX to T30_PHASE_D_TX 2012-03-26 22:02:52.084891 [DEBUG] mod_spandsp_fax.c:286 FLOW FAX Set rx type 0 2012-03-26 22:02:52.084891 [DEBUG] mod_spandsp_fax.c:286 FLOW FAX Set tx type 4 2012-03-26 22:02:53.144909 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Send complete in phase T30_PHASE_D_TX, state 14 2012-03-26 22:02:53.224929 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Send complete in phase T30_PHASE_D_TX, state 14 2012-03-26 22:02:53.224929 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Changing from phase T30_PHASE_D_TX to T30_PHASE_D_RX 2012-03-26 22:02:53.224929 [DEBUG] mod_spandsp_fax.c:286 FLOW FAX Set rx type 4 2012-03-26 22:02:53.224929 [DEBUG] mod_spandsp_fax.c:286 FLOW FAX Set tx type 0 2012-03-26 22:02:53.224929 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Start T4 2012-03-26 22:02:54.384927 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 HDLC signal status is Carrier up (-2) in state 14 2012-03-26 22:02:54.584907 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 HDLC signal status is Framing OK (-6) in state 14 2012-03-26 22:02:54.584907 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Start T4A 2012-03-26 22:02:55.604879 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Bad HDLC CRC received 2012-03-26 22:02:55.604879 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Bad CRC and timer is 7 2012-03-26 22:02:55.664879 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 HDLC signal status is Carrier down (-1) in state 14 2012-03-26 22:02:55.664879 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Start T4B 2012-03-26 22:02:55.684877 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 HDLC signal status is Carrier up (-2) in state 14 2012-03-26 22:02:55.684877 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Stop T4B (1440 remaining) 2012-03-26 22:02:55.704878 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 HDLC signal status is Carrier down (-1) in state 14 2012-03-26 22:02:55.704878 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Start T4B 2012-03-26 22:02:55.844910 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 HDLC signal status is Carrier up (-2) in state 14 2012-03-26 22:02:55.844910 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Stop T4B (480 remaining) 2012-03-26 22:02:55.844910 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 HDLC signal status is Carrier down (-1) in state 14 2012-03-26 22:02:55.844910 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Start T4B 2012-03-26 22:02:56.024878 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 T4B expired in phase T30_PHASE_D_RX, state 14. The line is now quiet. 2012-03-26 22:02:56.024878 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 T4 expired in phase T30_PHASE_D_RX, state 14 2012-03-26 22:02:56.024878 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Retry number 2 2012-03-26 22:02:56.024878 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Repeat command called with nothing to repeat - phase T30_PHASE_D_RX, state 14 2012-03-26 22:02:56.264924 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 HDLC signal status is Carrier up (-2) in state 14 2012-03-26 22:02:56.284900 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 HDLC signal status is Carrier down (-1) in state 14 2012-03-26 22:02:56.804883 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 HDLC signal status is Carrier up (-2) in state 14 2012-03-26 22:02:56.824909 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 HDLC signal status is Carrier down (-1) in state 14 2012-03-26 22:02:56.864878 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 HDLC signal status is Carrier up (-2) in state 14 2012-03-26 22:02:56.864878 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 HDLC signal status is Carrier down (-1) in state 14 2012-03-26 22:02:56.964906 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 HDLC signal status is Carrier up (-2) in state 14 2012-03-26 22:02:56.984901 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 HDLC signal status is Carrier down (-1) in state 14 2012-03-26 22:02:57.084900 [DEBUG] ftmod_libpri.c:1065 -- Hangup REQ on channel 4:1 2012-03-26 22:02:57.084900 [DEBUG] ftmod_libpri.c:1078 [s4c1][4:1] Changed state from UP to TERMINATING 2012-03-26 22:02:57.084900 [DEBUG] ftdm_state.c:511 [s4c1][4:1] Executing state processor for TERMINATING 2012-03-26 22:02:57.084900 [DEBUG] ftmod_libpri.c:679 -- 4:1 STATE [TERMINATING] 2012-03-26 22:02:57.084900 [DEBUG] ftmod_libpri.c:687 [s4c1][4:1] Completed state change from UP to TERMINATING in 0ms 2012-03-26 22:02:57.084900 [DEBUG] ftdm_io.c:5586 [s4c1][4:1] Scheduling safety hangup timer 2012-03-26 22:02:57.084900 [DEBUG] mod_freetdm.c:2416 got clear channel sig [STOP] f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:57.084900 [DEBUG] switch_channel.c:2848 (FreeTDM/4:1/47615101) Callstate Change ACTIVE -> HANGUP f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:57.084900 [NOTICE] mod_freetdm.c:2441 Hangup FreeTDM/4:1/47615101 [CS_EXECUTE] [NORMAL_CLEARING] f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:57.084900 [DEBUG] switch_channel.c:2871 Send signal FreeTDM/4:1/47615101 [KILL] f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:57.084900 [DEBUG] switch_core_session.c:1180 Send signal FreeTDM/4:1/47615101 [BREAK] f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:57.104898 [DEBUG] mod_spandsp_fax.c:491 ============================================================================== f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:57.104898 [DEBUG] mod_spandsp_fax.c:504 Fax processing not successful - result (49) The call dropped prematurely. f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:57.104898 [DEBUG] mod_spandsp_fax.c:509 Remote station id: 05322405354 f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:57.104898 [DEBUG] mod_spandsp_fax.c:510 Local station id: Sangoma Fax Ident f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:57.104898 [DEBUG] mod_spandsp_fax.c:511 Pages transferred: 4 f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:57.104898 [DEBUG] mod_spandsp_fax.c:513 Total fax pages: 4 f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:57.104898 [DEBUG] mod_spandsp_fax.c:514 Image resolution: 8031x3850 f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:57.104898 [DEBUG] mod_spandsp_fax.c:515 Transfer Rate: 4800 f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:57.104898 [DEBUG] mod_spandsp_fax.c:517 ECM status on f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:57.104898 [DEBUG] mod_spandsp_fax.c:518 remote country: f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:57.104898 [DEBUG] mod_spandsp_fax.c:519 remote vendor: f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:57.104898 [DEBUG] mod_spandsp_fax.c:520 remote model: f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:57.104898 [DEBUG] mod_spandsp_fax.c:522 ============================================================================== 2012-03-26 22:02:57.104898 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Changing from state 14 to 32 2012-03-26 22:02:57.104898 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Changing from phase T30_PHASE_D_RX to T30_PHASE_CALL_FINISHED regards, Anita On Tue, Mar 27, 2012 at 12:54 AM, Anita Hall <anita.hall@simmortel.com>wrote:
Hi
The dialplan just sends the control to a python script over ESL which gives rxfax(filename.tiff)
I have tried giving the rxfax() command in the dialplan itself with similar results. Many calls drop prematuresly and a good many fail to receive DCS after permitted retries.
regards, Anita
On Sat, Mar 24, 2012 at 9:24 PM, Anton Kvashenkin <anton.jugatsu@gmail.com
wrote:
Can you show dialplan snippet. 24.03.2012 19:24 пользователь "Anita Hall" <anita.hall@simmortel.com> написал:
Hi
My client had been using an old torrenta cards which game problems with pretty much everything :) After evangelizing the cause of Sangoma for more than 3 months (yes, they are dumb), they are finally making the transition so I am pretty excited. The choice of card is A108D which does a whole bunch of DSP in the hardware.
Now, the first hurdle that I have to make Sangoma jump across is getting incoming Fax over E1 right. We are using mod_spandsp, of course. So, here I will be needing a whole lot of help from the veterans of spandsp and Faxing :) I desperately need Sangoma to pass the Fax test or they will give me torrenta cards all over again!
The primary cause of failures are - (49) The call dropped prematurely and (48) Disconnected after permitted retries.
For example, in this case, can I conclude that the other end did not provide a Fax tone or is it something else?
2aeb5f7c-75b5-11e1-8f36-b3286880c45b EXECUTE FreeTDM/4:2/47615728 rxfax(/srv/fax/in/2aeb5f7c-75b5-11e1-8f36-b3286880c45b.tiff) 2aeb5f7c-75b5-11e1-8f36-b3286880c45b 2012-03-24 18:57:57.824906 [DEBUG] mod_spandsp_fax.c:1357 Raw read codec activation Success L16 20000 2aeb5f7c-75b5-11e1-8f36-b3286880c45b 2012-03-24 18:57:57.824906 [DEBUG] switch_core_codec.c:216 FreeTDM/4:2/47615728 Push codec L16:70 2aeb5f7c-75b5-11e1-8f36-b3286880c45b 2012-03-24 18:57:57.824906 [DEBUG] mod_spandsp_fax.c:1373 Raw write codec activation Success L16 2012-03-24 18:57:57.844876 [DEBUG] ftmod_wanpipe.c:965 [s4c2][4:2] First packet read stats: Rx queue len: 1, Rx queue size: 10 2012-03-24 18:57:57.904879 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 HDLC signal status is Carrier up (-2) in state 17 2012-03-24 18:57:57.924878 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 HDLC signal status is Carrier down (-1) in state 17 2012-03-24 18:57:58.104877 [DEBUG] ftmod_wanpipe.c:901 [s4c2][4:2] First packet write stats: Tx queue len: 1, Tx queue size: 5, Tx idle: 30 2012-03-24 18:57:58.444908 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 HDLC signal status is Carrier up (-2) in state 17 2012-03-24 18:57:58.644907 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 HDLC signal status is Carrier down (-1) in state 17 2012-03-24 18:57:58.664878 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 HDLC signal status is Carrier up (-2) in state 1 2012-03-24 18:57:58.764879 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 HDLC signal status is Carrier up (-2) in state 17 2012-03-24 18:57:58.764879 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 HDLC signal status is Carrier down (-1) in state 17 2012-03-24 18:57:58.784878 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 HDLC signal status is Carrier up (-2) in state 17 2012-03-24 18:57:58.804879 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 HDLC signal status is Carrier down (-1) in state 17 2012-03-24 18:57:59.244886 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 HDLC signal status is Carrier up (-2) in state 17 2012-03-24 18:57:59.464887 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 HDLC signal status is Carrier down (-1) in state 17 2012-03-24 18:57:59.564903 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 T4 expired in phase T30_PHASE_B_RX, state 17 2012-03-24 18:57:59.564903 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Retry number 1 2012-03-24 18:57:59.564903 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Changing from phase T30_PHASE_B_RX to T30_PHASE_B_TX 2012-03-24 18:57:59.564903 [DEBUG] mod_spandsp_fax.c:286 FLOW FAX Set rx type 0 2012-03-24 18:57:59.564903 [DEBUG] mod_spandsp_fax.c:286 FLOW FAX Set tx type 4 2012-03-24 18:57:59.564903 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Sending ident 'Sangoma Fax Ident' 2012-03-24 18:57:59.564903 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Tx: CSI without final frame tag 2012-03-24 18:57:59.564903 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Tx: ff 03 40 74 6e 65 64 49 20 78 61 46 20 61 6d 6f 67 6e 61 53 20 20 20 2012-03-24 18:58:00.524877 [DEBUG] ftmod_libpri.c:1065 -- Hangup REQ on channel 4:1 2012-03-24 18:58:00.524877 [DEBUG] ftmod_libpri.c:1078 [s4c1][4:1] Changed state from UP to TERMINATING 2012-03-24 18:58:00.524877 [DEBUG] ftdm_state.c:511 [s4c1][4:1] Executing state processor for TERMINATING
I will need some more hand-holding with logs later :)
regards, Anita
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com
Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
_________________________________________________________________________ Professional FreeSWITCH Consulting Services: consulting@freeswitch.org http://www.freeswitchsolutions.com
FreeSWITCH-powered IP PBX: The CudaTel Communication Server http://www.cudatel.com
Official FreeSWITCH Sites http://www.freeswitch.org http://wiki.freeswitch.org http://www.cluecon.com
FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org