[asterisk-users] Faxes suddenly failing
Steve Underwood
steveu at coppice.org
Thu Sep 1 07:43:18 CDT 2011
Hi Tim,
On 09/01/2011 03:49 AM, Tim King wrote:
> I realize that faxing is not great with voip but here is my confusion.
> I have been working on a web based fax system for 2 weeks. During this
> time I have sent over 100 2 page faxes without any errors. Now today
> as things are finally completed I can not seem to get any fax to go
> through unless it is a 1 page cover only. Anyone able to tell the
> issue from this debug output?
>
> -- Channel 'SIP/MyVoipProvider-00000046' FAX session '12' started
> -- FAX handle 0: [ 000.000038 ], STAT_EVT_STRT_RX st:
> IDLE rt: IDLENSRX
> -- FAX handle 0: [ 000.000184 ], STAT_EVT_RX_HW_RDY st:
> WT_RX_HW_RDY rt: RRDYNHRY
> -- FAX handle 0: [ 000.000504 ], P30EVN_RECEIVE_STARTED
> -- FAX handle 0: [ 000.000538 ], STAT_INFO_CSI
> -- FAX handle 0: [ 000.000568 ], STAT_INFO_DIS
> > Channel 'SIP/MyVoipProvider-00000046' fax session '12', [ 000.091837
> ], stack sent 5 frames (100 ms) of energy.
> > Channel 'SIP/MyVoipProvider-00000046' fax session '12', [ 000.160248
> ], stack sent 3 frames (60 ms) of silence.
> > Channel 'SIP/MyVoipProvider-00000046' fax session '12', [ 000.960201
> ], channel sent 48 frames (960 ms) of silence.
> > Channel 'SIP/MyVoipProvider-00000046' fax session '12', [ 000.979464
> ], channel sent 1 frames (20 ms) of energy.
> > Channel 'SIP/MyVoipProvider-00000046' fax session '12', [ 003.157848
> ], stack sent 150 frames (3000 ms) of energy.
> > Channel 'SIP/MyVoipProvider-00000046' fax session '12', [ 003.219814
> ], stack sent 3 frames (60 ms) of silence.
> -- FAX handle 0: [ 005.240927 ], STAT_EVT_TX_V21_DONE st:
> WT_DIS_RSP rt: WDSRNT21
> > Channel 'SIP/MyVoipProvider-00000046' fax session '12', [ 005.579811
> ], stack sent 118 frames (2360 ms) of energy.
> > Channel 'SIP/MyVoipProvider-00000046' fax session '12', [ 006.481179
> ], channel sent 275 frames (5500 ms) of silence.
> > Channel 'SIP/MyVoipProvider-00000046' fax session '12', [ 007.801045
> ], channel sent 66 frames (1320 ms) of energy.
> -- FAX handle 0: [ 007.800554 ], STAT_FRM_CRP
> -- FAX handle 0: [ 007.800586 ], STAT_EVT_CRP st:
> WT_DIS_RSP rt: XXXXNT4X
> -- FAX handle 0: [ 007.800602 ], STAT_EVT_FSC_ERR st:
> WT_DIS_RSP rt: UNEXPECT
> -- FAX handle 0: [ 011.012832 ], STAT_EVT_RX_TRN_END st:
> WT_DIS_RSP rt: RXXXNFRX
> -- FAX handle 0: [ 011.012878 ], STAT_INFO_CSI
> -- FAX handle 0: [ 011.012905 ], STAT_INFO_DIS
> > Channel 'SIP/MyVoipProvider-00000046' fax session '12', [ 011.152812
> ], stack sent 279 frames (5580 ms) of silence.
> -- FAX handle 0: [ 013.179561 ], STAT_EVT_TX_V21_DONE st:
> WT_DIS_RSP rt: WDSRNT21
> > Channel 'SIP/MyVoipProvider-00000046' fax session '12', [ 013.471827
> ], stack sent 116 frames (2320 ms) of energy.
> > Channel 'SIP/MyVoipProvider-00000046' fax session '12', [ 014.260642
> ], channel sent 323 frames (6460 ms) of silence.
> -- FAX handle 0: [ 016.119786 ], STAT_INFO_TSI
> > Channel 'SIP/MyVoipProvider-00000046' fax session '12', [ 016.460661
> ], channel sent 110 frames (2200 ms) of energy.
> -- FAX handle 0: [ 016.460394 ], STAT_INFO_DCS
> -- FAX handle 0: [ 016.460431 ], STAT_EVT_DCS st:
> WT_DIS_RSP rt: WDSRNDCS
> -- FAX handle 0: [ 016.460449 ], STAT_NEG_V17_14400
> -- FAX handle 0: [ 016.460464 ], STAT_NEG_MH
> -- FAX handle 0: [ 016.460476 ], STAT_NEG_A4
> -- FAX handle 0: [ 016.460488 ], STAT_NEG_RES_204x196
> -- FAX handle 0: [ 016.460500 ], STAT_NEG_ECM
> -- FAX handle 0: [ 016.460514 ], STAT_EVT_SW_ECM st:
> WT_DIS_RSP rt: WDSRNSWE
> > Channel 'SIP/MyVoipProvider-00000046' fax session '12', [ 016.540315
> ], channel sent 4 frames (80 ms) of silence.
> -- FAX handle 0: [ 016.800906 ], STAT_EVT_RX_IMG_STRT st:
> RCV_ECM_TRN rt: UNEXPECT
> > Channel 'SIP/MyVoipProvider-00000046' fax session '12', [ 019.700543
> ], channel sent 158 frames (3160 ms) of energy.
> -- FAX handle 0: [ 019.759984 ], STAT_EVT_RX_TRN_END st:
> RCV_ECM_TRN rt: RTCFNERT
> -- FAX handle 0: [ 019.760071 ], STAT_FRM_CFR
> > Channel 'SIP/MyVoipProvider-00000046' fax session '12', [ 019.912812
> ], stack sent 322 frames (6440 ms) of silence.
> -- FAX handle 0: [ 020.957834 ], STAT_EVT_TX_V21_DONE st:
> RCV_ECM_STRT rt: RECMNT21
> > Channel 'SIP/MyVoipProvider-00000046' fax session '12', [ 021.278809
> ], stack sent 68 frames (1360 ms) of energy.
> > Channel 'SIP/MyVoipProvider-00000046' fax session '12', [ 022.261160
> ], channel sent 128 frames (2560 ms) of silence.
> -- FAX handle 0: [ 022.517880 ], STAT_EVT_RX_IMG_STRT st:
> RCV_ECM_STRT rt: RECMNSRI
> -- FAX handle 0: [ 022.517982 ], P30EVN_PHASE_C
> -- FAX handle 0: [ 022.517998 ], P30EVN_DOC_START
> -- FAX handle 0: [ 022.518429 ], P30EVN_PAGE_START
> > Channel 'SIP/MyVoipProvider-00000046' fax session '12', [ 031.102000
> ], channel sent 442 frames (8840 ms) of energy.
> > Channel 'SIP/MyVoipProvider-00000046' fax session '12', [ 031.160415
> ], channel sent 3 frames (60 ms) of silence.
> -- FAX handle 0: [ 031.160196 ], STAT_EVT_RX_IMG_END st:
> RCV_ECM rt: RECMNERI
> -- FAX handle 0: [ 031.180491 ], STAT_EVT_RX_IMG_STRT st:
> F_END_ECM rt: UNEXPECT
> -- FAX handle 0: [ 031.180579 ], STAT_EVT_RX_IMG_END st:
> F_END_ECM rt: UNEXPECT
> -- FAX handle 0: [ 032.580514 ], STAT_INFO_PPS_MPS
> -- FAX handle 0: [ 032.580601 ], STAT_EVT_PPS_MPS st:
> F_END_ECM rt: FEEMNP_M
> -- FAX handle 0: [ 032.580625 ], P30EVN_PAGE_END
> -- FAX handle 0: [ 032.580639 ], STAT_FRM_MCF
The first page looks OK
> > Channel 'SIP/MyVoipProvider-00000046' fax session '12', [ 032.601247
> ], channel sent 72 frames (1440 ms) of energy.
> > Channel 'SIP/MyVoipProvider-00000046' fax session '12', [ 032.740976
> ], stack sent 573 frames (11460 ms) of silence.
> -- FAX handle 0: [ 033.771842 ], STAT_EVT_TX_V21_DONE st:
> RCV_ECM_STRT rt: RECMNT21
> > Channel 'SIP/MyVoipProvider-00000046' fax session '12', [ 034.094801
> ], stack sent 68 frames (1360 ms) of energy.
> > Channel 'SIP/MyVoipProvider-00000046' fax session '12', [ 035.101829
> ], channel sent 125 frames (2500 ms) of silence.
> -- FAX handle 0: [ 035.353869 ], STAT_EVT_RX_IMG_STRT st:
> RCV_ECM_STRT rt: RECMNSRI
> -- FAX handle 0: [ 035.353970 ], P30EVN_PHASE_C
> -- FAX handle 0: [ 035.353997 ], STAT_EVT_GO_TO_B st:
> RCV_ECM_STRT rt: XXXXNGOB
> -- FAX handle 0: [ 037.861871 ], STAT_EVT_HW_CLOSE st:
> WT_HW_CLS rt: WCLSNCLS
That's a weird series of events. Phase C starts, and 27us later (i.e.
immediately) things are changing to Phase B. It looks like either a
wacky T.38 frame was received, or the FAX engine has screwed up
internally. A PCAP file might reveal something, if you scan it to the
point where it matches up with this event.
> -- FAX handle 0: [ 037.862008 ], P30EVN_DOC_END
> -- FAX handle 0: [ 037.862024 ], STAT_SES_COMPLETE
> -- FAX handle 0: [ 037.862038 ], P30EVN_COMPLETE
> -- Channel 'SIP/MyVoipProvider-00000046' FAX session '12' is
> complete, result: 'FAILED' (FAX_FAILURE_PARTIAL), error: 'ECM_FAIL',
> pages: 1, resolution: '204x196', transfer rate: '14400', remoteSID:
> '16165551212'
>
>
> --
> _____________________________________________________________________
> -- Bandwidth and Colocation Provided by http://www.api-digital.com --
> New to Asterisk? Join us for a live introductory webinar every Thurs:
> http://www.asterisk.org/hello
>
> asterisk-users mailing list
> To UNSUBSCRIBE or update options visit:
> http://lists.digium.com/mailman/listinfo/asterisk-users
More information about the asterisk-users
mailing list