rendered paste body -- Executing [fax@macro-fax_auto_180:6] RxFAX("SIP/130-082321b0", "/var/spool/asterisk/fax/130-1188368607.8.tif|caller|debug|ecm") in new stack
[Aug 29 10:23:27] DEBUG[9302]: app_rxfax.c:622 rxfax_exec: Start parsing data
[Aug 29 10:23:27] DEBUG[9302]: app_rxfax.c:655 rxfax_exec: Resetting channel variables related to T38
[Aug 29 10:23:27] DEBUG[9302]: app_rxfax.c:681 rxfax_exec: Setting read format
[Aug 29 10:23:27] DEBUG[9302]: app_rxfax.c:687 rxfax_exec: Try set read AST_FORMAT_SLINEAR format (256 to 64)
[Aug 29 10:23:27] DEBUG[9302]: app_rxfax.c:697 rxfax_exec: Setting write format
[Aug 29 10:23:27] DEBUG[9302]: app_rxfax.c:701 rxfax_exec: Try set write AST_FORMAT_SLINEAR format (256 to 64)
[Aug 29 10:23:27] DEBUG[9302]: app_rxfax.c:716 rxfax_exec: Main loop
[Aug 29 10:23:27] DEBUG[9302]: app_rxfax.c:722 rxfax_exec: rxfax_audio
[Aug 29 10:23:27] DEBUG[9302]: app_rxfax.c:723 rxfax_exec: t38_status is '0'
[Aug 29 10:23:27] DEBUG[9302]: app_rxfax.c:362 rxfax_audio: Enter rxfax_audio file:/var/spool/asterisk/fax/130-1188368607.8.tif caller:1 debug:1 ecm:1
[Aug 29 10:23:27] DEBUG[9302]: app_rxfax.c:401 rxfax_audio: Enabling ECM mode for app_rxfax
[Aug 29 10:23:27] DEBUG[9302]: app_rxfax.c:77 span_message: FLOW T.30 HDLC carrier up in state 18
[Aug 29 10:23:27] DEBUG[9302]: app_rxfax.c:77 span_message: FLOW T.30 HDLC carrier down in state 18
[Aug 29 10:23:28] DEBUG[9302]: app_rxfax.c:77 span_message: FLOW T.30 HDLC carrier up in state 18
[Aug 29 10:23:28] DEBUG[9302]: app_rxfax.c:77 span_message: FLOW T.30 HDLC carrier down in state 18
[Aug 29 10:23:28] DEBUG[9302]: app_rxfax.c:446 rxfax_audio: Fax detected in RxFax !!!
[Aug 29 10:23:28] NOTICE[9302]: channel.c:2495 __ast_read: Dropping incompatible voice frame on SIP/130-082321b0 of format slin since our native format has changed to g729
[Aug 29 10:23:31] DEBUG[9302]: app_rxfax.c:77 span_message: FLOW T.30 HDLC carrier up in state 18
[Aug 29 10:23:31] DEBUG[9302]: app_rxfax.c:77 span_message: FLOW T.30 HDLC carrier down in state 18
[Aug 29 10:23:31] DEBUG[9302]: app_rxfax.c:446 rxfax_audio: Fax detected in RxFax !!!
[Aug 29 10:23:31] NOTICE[9302]: channel.c:2495 __ast_read: Dropping incompatible voice frame on SIP/130-082321b0 of format slin since our native format has changed to g729
[Aug 29 10:23:34] DEBUG[9302]: app_rxfax.c:77 span_message: FLOW T.30 HDLC carrier up in state 18
[Aug 29 10:23:35] DEBUG[9302]: app_rxfax.c:77 span_message: FLOW T.30 HDLC carrier down in state 18
[Aug 29 10:23:35] DEBUG[9302]: app_rxfax.c:446 rxfax_audio: Fax detected in RxFax !!!
[Aug 29 10:23:35] NOTICE[9302]: channel.c:2495 __ast_read: Dropping incompatible voice frame on SIP/130-082321b0 of format slin since our native format has changed to g729
[Aug 29 10:23:35] DEBUG[9302]: app_rxfax.c:77 span_message: FLOW T.30 HDLC carrier up in state 18
[Aug 29 10:23:35] DEBUG[9302]: app_rxfax.c:446 rxfax_audio: Fax detected in RxFax !!!
[Aug 29 10:23:35] DEBUG[9302]: app_rxfax.c:77 span_message: FLOW T.30 HDLC carrier down in state 18
[Aug 29 10:23:35] NOTICE[9302]: channel.c:2495 __ast_read: Dropping incompatible voice frame on SIP/130-082321b0 of format slin since our native format has changed to g729
[Aug 29 10:23:38] DEBUG[9302]: app_rxfax.c:77 span_message: FLOW T.30 HDLC carrier up in state 18
-- SIP/trunk_incomtel_1-1-0820ce70 answered SIP/100-08220150
[Aug 29 10:23:38] DEBUG[9302]: app_rxfax.c:446 rxfax_audio: Fax detected in RxFax !!!
[Aug 29 10:23:38] DEBUG[9302]: app_rxfax.c:77 span_message: FLOW T.30 HDLC carrier down in state 18
[Aug 29 10:23:38] NOTICE[9302]: channel.c:2495 __ast_read: Dropping incompatible voice frame on SIP/130-082321b0 of format slin since our native format has changed to g729
[Aug 29 10:23:38] DEBUG[9302]: app_rxfax.c:77 span_message: FLOW T.30 HDLC carrier up in state 18
[Aug 29 10:23:38] DEBUG[9302]: app_rxfax.c:77 span_message: FLOW T.30 HDLC carrier down in state 18
[Aug 29 10:23:39] DEBUG[9302]: app_rxfax.c:446 rxfax_audio: Fax detected in RxFax !!!
[Aug 29 10:23:39] NOTICE[9302]: channel.c:2495 __ast_read: Dropping incompatible voice frame on SIP/130-082321b0 of format slin since our native format has changed to g729
[Aug 29 10:24:18] DEBUG[9302]: app_rxfax.c:77 span_message: FLOW T.30 HDLC carrier up in state 18
[Aug 29 10:24:19] NOTICE[9251]: channel.c:901 ast_channel_perform_set_t38_status: Setting t38 status to 2 at chan_sip.c:5007
[Aug 29 10:24:19] DEBUG[9251]: chan_sip.c:13838 handle_request_invite: T38 state changed to 5 on channel SIP/130-082321b0
[Aug 29 10:24:19] NOTICE[9251]: channel.c:901 ast_channel_perform_set_t38_status: Setting t38 status to 2 at chan_sip.c:13840
[Aug 29 10:24:19] DEBUG[9251]: chan_sip.c:13841 handle_request_invite: T38mode enabled for channel SIP/130-082321b0
[Aug 29 10:24:19] DEBUG[9302]: app_rxfax.c:728 rxfax_exec: rxfax_t38
[Aug 29 10:24:19] DEBUG[9302]: app_rxfax.c:729 rxfax_exec: t38_status is '2'
[Aug 29 10:24:19] DEBUG[9302]: app_rxfax.c:303 rxfax_t38: Enabling ECM mode for app_rxfax
[Aug 29 10:24:19] DEBUG[9302]: app_rxfax.c:77 span_message: FLOW T.38 Tx 0: indicator no-signal
[Aug 29 10:24:19] DEBUG[9302]: app_rxfax.c:77 span_message: FLOW T.38 Rx 0: IFP 00
[Aug 29 10:24:19] DEBUG[9302]: app_rxfax.c:77 span_message: FLOW T.38 Rx 0: indicator no-signal
[Aug 29 10:24:19] DEBUG[9302]: app_rxfax.c:77 span_message: FLOW T.30 No signal is present
[Aug 29 10:24:20] DEBUG[9302]: app_rxfax.c:77 span_message: FLOW T.38 Tx 1: indicator cng
[Aug 29 10:24:20] WARNING[9302]: rtp.c:887 ast_rtcp_read: RTCP Read too short
[Aug 29 10:24:20] DEBUG[9302]: app_rxfax.c:739 rxfax_exec: Loop done
[Aug 29 10:24:20] DEBUG[9302]: app_rxfax.c:186 phase_e_handler: ==============================================================================
[Aug 29 10:24:20] DEBUG[9302]: app_rxfax.c:209 phase_e_handler: Fax receive not successful - result (51) The call dropped prematurely.
[Aug 29 10:24:20] DEBUG[9302]: app_rxfax.c:211 phase_e_handler: ==============================================================================
[Aug 29 10:24:20] DEBUG[9302]: app_rxfax.c:77 span_message: FLOW T.30 Changing from state 18 to 32
[Aug 29 10:24:20] DEBUG[9302]: app_rxfax.c:77 span_message: FLOW T.30 Changing from phase T30_PHASE_A_CNG to T30_PHASE_CALL_FINISHED
[Aug 29 10:24:20] DEBUG[9302]: app_rxfax.c:77 span_message: FLOW T.38T Set rx type 13
[Aug 29 10:24:20] DEBUG[9302]: app_rxfax.c:77 span_message: FLOW T.38T Set tx type 13
[Aug 29 10:24:20] DEBUG[9302]: app_rxfax.c:77 span_message: FLOW T.38T FAX exchange complete
[Aug 29 10:24:20] DEBUG[9302]: app_rxfax.c:745 rxfax_exec: Release fax
[Aug 29 10:24:20] DEBUG[9302]: app_rxfax.c:750 rxfax_exec: Restore channel read format
[Aug 29 10:24:20] DEBUG[9302]: app_rxfax.c:756 rxfax_exec: Restore channel write format
[[Aug 29 10:24:18] DEBUG[9302]: app_rxfax.c:77 span_message: FLOW T.30 HDLC carrier up in state 18
[Aug 29 10:24:19] NOTICE[9251]: channel.c:901 ast_channel_perform_set_t38_status: Setting t38 status to 2 at chan_sip.c:5007
[Aug 29 10:24:19] DEBUG[9251]: chan_sip.c:13838 handle_request_invite: T38 state changed to 5 on channel SIP/130-082321b0
[Aug 29 10:24:19] NOTICE[9251]: channel.c:901 ast_channel_perform_set_t38_status: Setting t38 status to 2 at chan_sip.c:13840
[Aug 29 10:24:19] DEBUG[9251]: chan_sip.c:13841 handle_request_invite: T38mode enabled for channel SIP/130-082321b0
[Aug 29 10:24:19] DEBUG[9302]: app_rxfax.c:728 rxfax_exec: rxfax_t38
[Aug 29 10:24:19] DEBUG[9302]: app_rxfax.c:729 rxfax_exec: t38_status is '2'
[Aug 29 10:24:19] DEBUG[9302]: app_rxfax.c:303 rxfax_t38: Enabling ECM mode for app_rxfax
[Aug 29 10:24:19] DEBUG[9302]: app_rxfax.c:77 span_message: FLOW T.38 Tx 0: indicator no-signal
[Aug 29 10:24:19] DEBUG[9302]: app_rxfax.c:77 span_message: FLOW T.38 Rx 0: IFP 00
[Aug 29 10:24:19] DEBUG[9302]: app_rxfax.c:77 span_message: FLOW T.38 Rx 0: indicator no-signal
[Aug 29 10:24:19] DEBUG[9302]: app_rxfax.c:77 span_message: FLOW T.30 No signal is present
[Aug 29 10:24:20] DEBUG[9302]: app_rxfax.c:77 span_message: FLOW T.38 Tx 1: indicator cng
[Aug 29 10:24:20] WARNING[9302]: rtp.c:887 ast_rtcp_read: RTCP Read too short
[Aug 29 10:24:20] DEBUG[9302]: app_rxfax.c:739 rxfax_exec: Loop done
[Aug 29 10:24:20] DEBUG[9302]: app_rxfax.c:186 phase_e_handler: ==============================================================================
[Aug 29 10:24:20] DEBUG[9302]: app_rxfax.c:209 phase_e_handler: Fax receive not successful - result (51) The call dropped prematurely.
[Aug 29 10:24:20] DEBUG[9302]: app_rxfax.c:211 phase_e_handler: ==============================================================================
[Aug 29 10:24:20] DEBUG[9302]: app_rxfax.c:77 span_message: FLOW T.30 Changing from state 18 to 32
[Aug 29 10:24:20] DEBUG[9302]: app_rxfax.c:77 span_message: FLOW T.30 Changing from phase T30_PHASE_A_CNG to T30_PHASE_CALL_FINISHED
[Aug 29 10:24:20] DEBUG[9302]: app_rxfax.c:77 span_message: FLOW T.38T Set rx type 13
[Aug 29 10:24:20] DEBUG[9302]: app_rxfax.c:77 span_message: FLOW T.38T Set tx type 13
[Aug 29 10:24:20] DEBUG[9302]: app_rxfax.c:77 span_message: FLOW T.38T FAX exchange complete
[Aug 29 10:24:20] DEBUG[9302]: app_rxfax.c:745 rxfax_exec: Release fax
[Aug 29 10:24:20] DEBUG[9302]: app_rxfax.c:750 rxfax_exec: Restore channel read format
[Aug 29 10:24:20] DEBUG[9302]: app_rxfax.c:756 rxfax_exec: Restore channel write format