[Freeswitch-users] txfax problems last git

Sat Apr 16 01:13:37 MSD 2011

Hi Madovsky!

Please use http://jira.freeswitch.org/ to report problems.

Thank you.

2011. április 15. 22:57:36 dátummal Madovsky az alábbiakat írta:
> before update it was working well
> 
> here is the log
> 
> 2011-04-15 16:54:07.685484 [DEBUG] mod_spandsp_fax.c:296 FLOW T.30 T4
> expired in phase T30_PHASE_B_RX, state 6 2011-04-15 16:54:07.685484
> [DEBUG] mod_spandsp_fax.c:296 FLOW T.30 Retry number 2 2011-04-15
> 16:54:07.685484 [DEBUG] mod_spandsp_fax.c:296 FLOW T.30 Changing from
> phase T30_PHASE_B_RX to T30_PHASE_B_TX 2011-04-15 16:54:07.685484 [DEBUG]
> mod_spandsp_fax.c:296 FLOW FAX Set rx type 0 2011-04-15 16:54:07.685484
> [DEBUG] mod_spandsp_fax.c:296 FLOW FAX Set tx type 4 2011-04-15
> 16:54:07.685484 [DEBUG] mod_spandsp_fax.c:296 FLOW T.30 DCS: 2011-04-15
> 16:54:07.685484 [DEBUG] mod_spandsp_fax.c:296 FLOW T.30   .... ...0= Store
> and forward Internet fax (T.37): Not set 2011-04-15 16:54:07.685484
> [DEBUG] mod_spandsp_fax.c:296 FLOW T.30   .... .0..= Real-time Internet
> fax (T.38): Not set 2011-04-15 16:54:07.685484 [DEBUG]
> mod_spandsp_fax.c:296 FLOW T.30   .... 0...= 3G mobile network: Not set
> 2011-04-15 16:54:07.685484 [DEBUG] mod_spandsp_fax.c:296 FLOW T.30   ....
> ..1.= Receive fax: Set 2011-04-15 16:54:07.685484 [DEBUG]
> mod_spandsp_fax.c:296 FLOW T.30   ..10 00..= Selected data signalling
> rate: V.17 14400bps 2011-04-15 16:54:07.685484 [DEBUG]
> mod_spandsp_fax.c:296 FLOW T.30   .1.. ....= R8x7.7lines/mm and/or
> 200x200pels/25.4mm: Set 2011-04-15 16:54:07.685484 [DEBUG]
> mod_spandsp_fax.c:296 FLOW T.30   1... ....= 2-D coding: Set 2011-04-15
> 16:54:07.685484 [DEBUG] mod_spandsp_fax.c:296 FLOW T.30   .... ..00=
> Recording width: 215mm +- 1% 2011-04-15 16:54:07.685484 [DEBUG]
> mod_spandsp_fax.c:296 FLOW T.30   .... 10..= Recording length: Unlimited
> 2011-04-15 16:54:07.685484 [DEBUG] mod_spandsp_fax.c:296 FLOW T.30   .111
> ....= Minimum scan line time: 0ms 2011-04-15 16:54:07.685484 [DEBUG]
> mod_spandsp_fax.c:296 FLOW T.30   0... ....= Extension indicator: Not set
> 2011-04-15 16:54:07.685484 [DEBUG] mod_spandsp_fax.c:296 FLOW T.30
> Changing from state 6 to 4 2011-04-15 16:54:07.685484 [DEBUG]
> mod_spandsp_fax.c:296 FLOW T.30 Sending ident 'boophone.com' 2011-04-15
> 16:54:07.685484 [DEBUG] mod_spandsp_fax.c:296 FLOW T.30 Tx:  TSI without
> final frame tag 2011-04-15 16:54:07.685484 [DEBUG] mod_spandsp_fax.c:296
> FLOW T.30 Tx:  ff 03 43 6d 6f 63 2e 65 6e 6f 68 70 6f 6f 62 20 20 20 20 20
> 20 20 20 2011-04-15 16:54:09.265684 [DEBUG] mod_spandsp_fax.c:296 FLOW
> T.30 Send complete in phase T30_PHASE_B_TX, state 4 2011-04-15
> 16:54:09.265684 [DEBUG] mod_spandsp_fax.c:296 FLOW T.30 DCS: 2011-04-15
> 16:54:09.265684 [DEBUG] mod_spandsp_fax.c:296 FLOW T.30   .... ...0= Store
> and forward Internet fax (T.37): Not set 2011-04-15 16:54:09.265684
> [DEBUG] mod_spandsp_fax.c:296 FLOW T.30   .... .0..= Real-time Internet
> fax (T.38): Not set 2011-04-15 16:54:09.265684 [DEBUG]
> mod_spandsp_fax.c:296 FLOW T.30   .... 0...= 3G mobile network: Not set
> 2011-04-15 16:54:09.265684 [DEBUG] mod_spandsp_fax.c:296 FLOW T.30   ....
> ..1.= Receive fax: Set 2011-04-15 16:54:09.265684 [DEBUG]
> mod_spandsp_fax.c:296 FLOW T.30   ..10 00..= Selected data signalling
> rate: V.17 14400bps 2011-04-15 16:54:09.265684 [DEBUG]
> mod_spandsp_fax.c:296 FLOW T.30   .1.. ....= R8x7.7lines/mm and/or
> 200x200pels/25.4mm: Set 2011-04-15 16:54:09.265684 [DEBUG]
> mod_spandsp_fax.c:296 FLOW T.30   1... ....= 2-D coding: Set 2011-04-15
> 16:54:09.265684 [DEBUG] mod_spandsp_fax.c:296 FLOW T.30   .... ..00=
> Recording width: 215mm +- 1% 2011-04-15 16:54:09.265684 [DEBUG]
> mod_spandsp_fax.c:296 FLOW T.30   .... 10..= Recording length: Unlimited
> 2011-04-15 16:54:09.265684 [DEBUG] mod_spandsp_fax.c:296 FLOW T.30   .111
> ....= Minimum scan line time: 0ms 2011-04-15 16:54:09.265684 [DEBUG]
> mod_spandsp_fax.c:296 FLOW T.30   0... ....= Extension indicator: Not set
> 2011-04-15 16:54:09.265684 [DEBUG] mod_spandsp_fax.c:296 FLOW T.30 Tx: 
> DCS with final frame tag 2011-04-15 16:54:09.265684 [DEBUG]
> mod_spandsp_fax.c:296 FLOW T.30 Tx:  ff 13 83 00 e2 78 2011-04-15
> 16:54:09.546048 [DEBUG] mod_spandsp_fax.c:296 FLOW T.30 Send complete in
> phase T30_PHASE_B_TX, state 4 2011-04-15 16:54:09.626076 [DEBUG]
> mod_spandsp_fax.c:296 FLOW T.30 Send complete in phase T30_PHASE_B_TX,
> state 4 2011-04-15 16:54:09.626076 [DEBUG] mod_spandsp_fax.c:296 FLOW T.30
> Changing from state 4 to 5 2011-04-15 16:54:09.626076 [DEBUG]
> mod_spandsp_fax.c:296 FLOW T.30 Changing from phase T30_PHASE_B_TX to
> T30_PHASE_C_NON_ECM_TX 2011-04-15 16:54:09.626076 [DEBUG]
> mod_spandsp_fax.c:296 FLOW FAX Set rx type 0 2011-04-15 16:54:09.626076
> [DEBUG] mod_spandsp_fax.c:296 FLOW FAX Set rx type 0 2011-04-15
> 16:54:09.626076 [DEBUG] mod_spandsp_fax.c:296 FLOW FAX Set tx type 7
> 2011-04-15 16:54:12.645314 [DEBUG] mod_spandsp_fax.c:296 FLOW T.30 Send
> complete in phase T30_PHASE_C_NON_ECM_TX, state 5 2011-04-15
> 16:54:12.645314 [DEBUG] mod_spandsp_fax.c:296 FLOW T.30 Changing from
> phase T30_PHASE_C_NON_ECM_TX to T30_PHASE_B_RX 2011-04-15 16:54:12.645314
> [DEBUG] mod_spandsp_fax.c:296 FLOW FAX Set rx type 4 2011-04-15
> 16:54:12.645314 [DEBUG] mod_spandsp_fax.c:296 FLOW FAX Set tx type 0
> 2011-04-15 16:54:12.645314 [DEBUG] mod_spandsp_fax.c:296 FLOW T.30 Start
> T4 2011-04-15 16:54:12.645314 [DEBUG] mod_spandsp_fax.c:296 FLOW T.30
> Changing from state 5 to 6 2011-04-15 16:54:13.166347 [DEBUG]
> mod_nibblebill.c:572 Received request via SESSION_HEARTBEAT! 2011-04-15
> 16:54:13.166347 [DEBUG] mod_nibblebill.c:433 Attempting to bill at
> $0.17304 per minute to account 9999999999999 2011-04-15 16:54:13.166347
> [DEBUG] mod_nibblebill.c:491 30 seconds passed since last bill time of
> 2011-04-15 16:53:43 2011-04-15 16:54:13.166347 [DEBUG]
> mod_nibblebill.c:498 Billing $0.086548 to 9999999999999 (Call:
> 1132765120 at 67.205.80.135 / 0.000009 so far) 2011-04-15 16:54:13.166347
> [DEBUG] mod_nibblebill.c:321 Doing update query [UPDATE accounts SET
> cash=cash-0.086548 WHERE id='9999999999999']
> 2011-04-15 16:54:13.288037 [DEBUG] mod_nibblebill.c:366 Doing lookup query
> [SELECT cash AS nibble_balance FROM accounts WHERE id='9999999999999']
> 2011-04-15 16:54:13.293107 [DEBUG] mod_nibblebill.c:376 Retrieved current
> balance for account 9999999999999 (balance = 6.655555) 2011-04-15
> 16:54:16.105756 [DEBUG] mod_spandsp_fax.c:296 FLOW T.30 T4 expired in
> phase T30_PHASE_B_RX, state 6 2011-04-15 16:54:16.105756 [DEBUG]
> mod_spandsp_fax.c:296 FLOW T.30 Too many retries. Giving up. 2011-04-15
> 16:54:16.105756 [DEBUG] mod_spandsp_fax.c:296 FLOW T.30 Changing from
> phase T30_PHASE_B_RX to T30_PHASE_D_TX 2011-04-15 16:54:16.105756 [DEBUG]
> mod_spandsp_fax.c:296 FLOW FAX Set rx type 0 2011-04-15 16:54:16.105756
> [DEBUG] mod_spandsp_fax.c:296 FLOW FAX Set tx type 4 2011-04-15
> 16:54:16.105756 [DEBUG] mod_spandsp_fax.c:296 FLOW T.30 Changing from
> state 6 to 3 2011-04-15 16:54:16.105756 [DEBUG] mod_spandsp_fax.c:296 FLOW
> T.30 Tx:  DCN with final frame tag 2011-04-15 16:54:16.105756 [DEBUG]
> mod_spandsp_fax.c:296 FLOW T.30 Tx:  ff 13 fb 2011-04-15 16:54:17.165849
> [DEBUG] mod_spandsp_fax.c:296 FLOW T.30 Send complete in phase
> T30_PHASE_D_TX, state 3 2011-04-15 16:54:17.245860 [DEBUG]
> mod_spandsp_fax.c:296 FLOW T.30 Send complete in phase T30_PHASE_D_TX,
> state 3 2011-04-15 16:54:17.245860 [DEBUG] mod_spandsp_fax.c:296 FLOW T.30
> Disconnecting 2011-04-15 16:54:17.245860 [DEBUG] mod_spandsp_fax.c:296
> FLOW T.30 Changing from phase T30_PHASE_D_TX to T30_PHASE_E 2011-04-15
> 16:54:17.245860 [DEBUG] mod_spandsp_fax.c:296 FLOW FAX Set rx type 0
> 2011-04-15 16:54:17.245860 [DEBUG] mod_spandsp_fax.c:296 FLOW FAX Set tx
> type 1 2011-04-15 16:54:17.245860 [DEBUG] mod_spandsp_fax.c:296 FLOW T.30
> Changing from state 3 to 2 2011-04-15 16:54:18.245661 [DEBUG]
> mod_spandsp_fax.c:296 FLOW T.30 Send complete in phase T30_PHASE_E, state
> 2 2011-04-15 16:54:18.245661 [DEBUG] mod_spandsp_fax.c:333
> ==========================================================================
> ==== 2011-04-15 16:54:18.245661 [DEBUG] mod_spandsp_fax.c:345 Fax
> processing not successful - result (20) Received no response to DCS or
> TCF. 2011-04-15 16:54:18.245661 [DEBUG] mod_spandsp_fax.c:350 Remote
> station id: 33456809528 2011-04-15 16:54:18.245661 [DEBUG]
> mod_spandsp_fax.c:351 Local station id:  boophone.com 2011-04-15
> 16:54:18.245661 [DEBUG] mod_spandsp_fax.c:352 Pages transferred: 0
> 2011-04-15 16:54:18.245661 [DEBUG] mod_spandsp_fax.c:354 Total fax pages: 
>  1 2011-04-15 16:54:18.245661 [DEBUG] mod_spandsp_fax.c:355 Image
> resolution:  8031x7700 2011-04-15 16:54:18.245661 [DEBUG]
> mod_spandsp_fax.c:356 Transfer Rate:     14400 2011-04-15 16:54:18.245661
> [DEBUG] mod_spandsp_fax.c:358 ECM status         off 2011-04-15
> 16:54:18.245661 [DEBUG] mod_spandsp_fax.c:359 remote country: 2011-04-15
> 16:54:18.245661 [DEBUG] mod_spandsp_fax.c:360 remote vendor: 2011-04-15
> 16:54:18.245661 [DEBUG] mod_spandsp_fax.c:361 remote model: 2011-04-15
> 16:54:18.245661 [DEBUG] mod_spandsp_fax.c:363
> ==========================================================================
> ==== 2011-04-15 16:54:18.245661 [DEBUG] switch_core_session.c:954 Send
> signal sofia/external/0033456809528 [BREAK] 2011-04-15 16:54:18.245661
> [DEBUG] mod_spandsp_fax.c:296 FLOW T.30 Changing from state 2 to 32
> 2011-04-15 16:54:18.245661 [DEBUG] mod_spandsp_fax.c:296 FLOW T.30
> Changing from phase T30_PHASE_E to T30_PHASE_CALL_FINISHED 2011-04-15
> 16:54:18.245661 [DEBUG] mod_spandsp_fax.c:296 FLOW FAX Set rx type 9
> 2011-04-15 16:54:18.245661 [DEBUG] mod_spandsp_fax.c:296 FLOW FAX FAX
> exchange complete 2011-04-15 16:54:18.245661 [DEBUG] mod_spandsp_fax.c:296
> FLOW FAX Set tx type 9 2011-04-15 16:54:18.245661 [DEBUG]
> mod_spandsp_fax.c:296 FLOW FAX FAX exchange complete 2011-04-15
> 16:54:18.265918 [DEBUG] switch_core_codec.c:141
> sofia/external/0033456809528 Restore previous codec PCMU:0.
> 
> 
> 
> my dialplan
> 
>                 <extension name="sendfax">
>                         <condition field="destination_number"
> expression="^sendfax$"> <action application="set"
> data="fax_enable_t38_request=false"/> <action application="set"
> data="fax_enable_t38=true"/> <action application="txfax"
> data="${fax_path}"/> <action application="hangup"/>
>                         </condition>
>                 </extension>
> 
> 
> Thanks !
> 
> Franck