Here is a log when the call drops in Phase D after having received 4 pages!<br><br>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?<br>
<br>f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:52.024887 [DEBUG] mod_spandsp_fax.c:428 ==== Page Received ===========================================================<br>f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:52.024887 [DEBUG] mod_spandsp_fax.c:429 Page no = 4<br>
f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:52.024887 [DEBUG] mod_spandsp_fax.c:430 Image size = 1728 x 999 pixels<br>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<br>
f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:52.024887 [DEBUG] mod_spandsp_fax.c:432 Compression = T.6 (3)<br>f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:52.024887 [DEBUG] mod_spandsp_fax.c:433 Compressed image size = 22935 bytes<br>
f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:52.024887 [DEBUG] mod_spandsp_fax.c:434 Bad rows = 0<br>f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:52.024887 [DEBUG] mod_spandsp_fax.c:435 Longest bad row run = 0<br>
f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:52.024887 [DEBUG] mod_spandsp_fax.c:436 ==============================================================================<br>2012-03-26 22:02:52.024887 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Changing from state 13 to 14<br>
2012-03-26 22:02:52.024887 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Tx: MCF with final frame tag<br>2012-03-26 22:02:52.024887 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Tx: ff 13 8c<br>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<br>
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<br>2012-03-26 22:02:52.084891 [DEBUG] mod_spandsp_fax.c:286 FLOW FAX Set rx type 0<br>2012-03-26 22:02:52.084891 [DEBUG] mod_spandsp_fax.c:286 FLOW FAX Set tx type 4<br>
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<br>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<br>
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<br>2012-03-26 22:02:53.224929 [DEBUG] mod_spandsp_fax.c:286 FLOW FAX Set rx type 4<br>2012-03-26 22:02:53.224929 [DEBUG] mod_spandsp_fax.c:286 FLOW FAX Set tx type 0<br>
2012-03-26 22:02:53.224929 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Start T4<br>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<br>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<br>
2012-03-26 22:02:54.584907 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Start T4A<br>2012-03-26 22:02:55.604879 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Bad HDLC CRC received<br>2012-03-26 22:02:55.604879 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Bad CRC and timer is 7<br>
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<br>2012-03-26 22:02:55.664879 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Start T4B<br>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<br>
2012-03-26 22:02:55.684877 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Stop T4B (1440 remaining)<br>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<br>2012-03-26 22:02:55.704878 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Start T4B<br>
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<br>2012-03-26 22:02:55.844910 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Stop T4B (480 remaining)<br>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<br>
2012-03-26 22:02:55.844910 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Start T4B<br>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.<br>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<br>
2012-03-26 22:02:56.024878 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Retry number 2<br>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<br>
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<br>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<br>
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<br>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<br>
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<br>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<br>
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<br>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<br>
2012-03-26 22:02:57.084900 [DEBUG] ftmod_libpri.c:1065 -- Hangup REQ on channel 4:1<br>2012-03-26 22:02:57.084900 [DEBUG] ftmod_libpri.c:1078 [s4c1][4:1] Changed state from UP to TERMINATING<br>2012-03-26 22:02:57.084900 [DEBUG] ftdm_state.c:511 [s4c1][4:1] Executing state processor for TERMINATING<br>
2012-03-26 22:02:57.084900 [DEBUG] ftmod_libpri.c:679 -- 4:1 STATE [TERMINATING]<br>2012-03-26 22:02:57.084900 [DEBUG] ftmod_libpri.c:687 [s4c1][4:1] Completed state change from UP to TERMINATING in 0ms<br>2012-03-26 22:02:57.084900 [DEBUG] ftdm_io.c:5586 [s4c1][4:1] Scheduling safety hangup timer<br>
2012-03-26 22:02:57.084900 [DEBUG] mod_freetdm.c:2416 got clear channel sig [STOP]<br>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<br>
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]<br>f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:57.084900 [DEBUG] switch_channel.c:2871 Send signal FreeTDM/4:1/47615101 [KILL]<br>
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]<br>f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:57.104898 [DEBUG] mod_spandsp_fax.c:491 ==============================================================================<br>
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.<br>f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:57.104898 [DEBUG] mod_spandsp_fax.c:509 Remote station id: 05322405354<br>
f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:57.104898 [DEBUG] mod_spandsp_fax.c:510 Local station id: Sangoma Fax Ident<br>f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:57.104898 [DEBUG] mod_spandsp_fax.c:511 Pages transferred: 4<br>
f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:57.104898 [DEBUG] mod_spandsp_fax.c:513 Total fax pages: 4<br>f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:57.104898 [DEBUG] mod_spandsp_fax.c:514 Image resolution: 8031x3850<br>
f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:57.104898 [DEBUG] mod_spandsp_fax.c:515 Transfer Rate: 4800<br>f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:57.104898 [DEBUG] mod_spandsp_fax.c:517 ECM status on<br>
f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:57.104898 [DEBUG] mod_spandsp_fax.c:518 remote country:<br>f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:57.104898 [DEBUG] mod_spandsp_fax.c:519 remote vendor:<br>
f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:57.104898 [DEBUG] mod_spandsp_fax.c:520 remote model:<br>f1a680ea-7760-11e1-b0ea-b3286880c45b 2012-03-26 22:02:57.104898 [DEBUG] mod_spandsp_fax.c:522 ==============================================================================<br>
2012-03-26 22:02:57.104898 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Changing from state 14 to 32<br>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<br>
<br><br><br><br><br><br><br clear="all">regards,<br>Anita<br><br>
<br><br><div class="gmail_quote">On Tue, Mar 27, 2012 at 12:54 AM, Anita Hall <span dir="ltr"><<a href="mailto:anita.hall@simmortel.com">anita.hall@simmortel.com</a>></span> wrote:<br><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">
Hi<br><br>The dialplan just sends the control to a python script over ESL which gives rxfax(filename.tiff)<br><br>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. <br>
<br><br clear="all">regards,<br>Anita<div class="HOEnZb"><div class="h5"><br><br>
<br><br><div class="gmail_quote">On Sat, Mar 24, 2012 at 9:24 PM, Anton Kvashenkin <span dir="ltr"><<a href="mailto:anton.jugatsu@gmail.com" target="_blank">anton.jugatsu@gmail.com</a>></span> wrote:<br><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">
<p>Can you show dialplan snippet.</p>
<div class="gmail_quote">24.03.2012 19:24 пользователь "Anita Hall" <<a href="mailto:anita.hall@simmortel.com" target="_blank">anita.hall@simmortel.com</a>> написал:<br type="attribution"><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">
<div><div>
Hi<br><br>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. <br>
<br>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!<br>
<br>The primary cause of failures are - (49) The call dropped prematurely and (48) Disconnected after permitted retries. <br><br>For example, in this case, can I conclude that the other end did not provide a Fax tone or is it something else?<br>
<br>2aeb5f7c-75b5-11e1-8f36-b3286880c45b EXECUTE FreeTDM/4:2/47615728 rxfax(/srv/fax/in/2aeb5f7c-75b5-11e1-8f36-b3286880c45b.tiff)<br>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<br>
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<br>2aeb5f7c-75b5-11e1-8f36-b3286880c45b 2012-03-24 18:57:57.824906 [DEBUG] mod_spandsp_fax.c:1373 Raw write codec activation Success L16<br>
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<br>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<br>
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<br>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<br>
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<br>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<br>
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<br>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<br>
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<br>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<br>
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<br>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<br>
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<br>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<br>
2012-03-24 18:57:59.564903 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Retry number 1<br>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<br>2012-03-24 18:57:59.564903 [DEBUG] mod_spandsp_fax.c:286 FLOW FAX Set rx type 0<br>
2012-03-24 18:57:59.564903 [DEBUG] mod_spandsp_fax.c:286 FLOW FAX Set tx type 4<br>2012-03-24 18:57:59.564903 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Sending ident 'Sangoma Fax Ident'<br>2012-03-24 18:57:59.564903 [DEBUG] mod_spandsp_fax.c:286 FLOW T.30 Tx: CSI without final frame tag<br>
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<br>2012-03-24 18:58:00.524877 [DEBUG] ftmod_libpri.c:1065 -- Hangup REQ on channel 4:1<br>
2012-03-24 18:58:00.524877 [DEBUG] ftmod_libpri.c:1078 [s4c1][4:1] Changed state from UP to TERMINATING<br>2012-03-24 18:58:00.524877 [DEBUG] ftdm_state.c:511 [s4c1][4:1] Executing state processor for TERMINATING<br><br>
<br>
I will need some more hand-holding with logs later :)<br><br><br clear="all">regards,<br>Anita<br><br>
<br></div></div>_________________________________________________________________________<br>
Professional FreeSWITCH Consulting Services:<br>
<a href="mailto:consulting@freeswitch.org" target="_blank">consulting@freeswitch.org</a><br>
<a href="http://www.freeswitchsolutions.com" target="_blank">http://www.freeswitchsolutions.com</a><br>
<br>
FreeSWITCH-powered IP PBX: The CudaTel Communication Server<br>
<a href="http://www.cudatel.com" target="_blank">http://www.cudatel.com</a><br>
<br>
Official FreeSWITCH Sites<br>
<a href="http://www.freeswitch.org" target="_blank">http://www.freeswitch.org</a><br>
<a href="http://wiki.freeswitch.org" target="_blank">http://wiki.freeswitch.org</a><br>
<a href="http://www.cluecon.com" target="_blank">http://www.cluecon.com</a><br>
<br>
FreeSWITCH-users mailing list<br>
<a href="mailto:FreeSWITCH-users@lists.freeswitch.org" target="_blank">FreeSWITCH-users@lists.freeswitch.org</a><br>
<a href="http://lists.freeswitch.org/mailman/listinfo/freeswitch-users" target="_blank">http://lists.freeswitch.org/mailman/listinfo/freeswitch-users</a><br>
UNSUBSCRIBE:<a href="http://lists.freeswitch.org/mailman/options/freeswitch-users" target="_blank">http://lists.freeswitch.org/mailman/options/freeswitch-users</a><br>
<a href="http://www.freeswitch.org" target="_blank">http://www.freeswitch.org</a><br>
<br></blockquote></div>
<br>_________________________________________________________________________<br>
Professional FreeSWITCH Consulting Services:<br>
<a href="mailto:consulting@freeswitch.org" target="_blank">consulting@freeswitch.org</a><br>
<a href="http://www.freeswitchsolutions.com" target="_blank">http://www.freeswitchsolutions.com</a><br>
<br>
FreeSWITCH-powered IP PBX: The CudaTel Communication Server<br>
<a href="http://www.cudatel.com" target="_blank">http://www.cudatel.com</a><br>
<br>
Official FreeSWITCH Sites<br>
<a href="http://www.freeswitch.org" target="_blank">http://www.freeswitch.org</a><br>
<a href="http://wiki.freeswitch.org" target="_blank">http://wiki.freeswitch.org</a><br>
<a href="http://www.cluecon.com" target="_blank">http://www.cluecon.com</a><br>
<br>
FreeSWITCH-users mailing list<br>
<a href="mailto:FreeSWITCH-users@lists.freeswitch.org" target="_blank">FreeSWITCH-users@lists.freeswitch.org</a><br>
<a href="http://lists.freeswitch.org/mailman/listinfo/freeswitch-users" target="_blank">http://lists.freeswitch.org/mailman/listinfo/freeswitch-users</a><br>
UNSUBSCRIBE:<a href="http://lists.freeswitch.org/mailman/options/freeswitch-users" target="_blank">http://lists.freeswitch.org/mailman/options/freeswitch-users</a><br>
<a href="http://www.freeswitch.org" target="_blank">http://www.freeswitch.org</a><br>
<br></blockquote></div><br>
</div></div></blockquote></div><br>