Can someone please help confirm if Email to Fax with Tiff is broken due to a bug in 3.21?

[VCCS Telecom]

I haven't been able to process a tiff file in 3.21-33 when sending an email to fax. I receive the following error:

Oct  5 04:40:29 kz 2600hz[5409]: |undefined|fax_smtp:132 (<0.8837.0>) Handle Data From <<"email">> to [<<"tel#@email.com">>]

Oct  5 04:40:29 kz 2600hz[5409]: |undefined|fax_smtp:142 (<0.8837.0>) Message decoded successfully!

Oct  5 04:40:29 kz 2600hz[5409]: |undefined|fax_smtp:641 (<0.8837.0>) processing multipart/mixed

Oct  5 04:40:29 kz 2600hz[5409]: |undefined|fax_smtp:651 (<0.8837.0>) processing multiple parts, first is text/plain

Oct  5 04:40:29 kz 2600hz[5409]: |undefined|fax_smtp:701 (<0.8837.0>) ignoring part text/plain

Oct  5 04:40:29 kz 2600hz[5409]: |undefined|fax_smtp:707 (<0.8837.0>) part is image/tiff

Oct  5 04:40:29 kz 2600hz[5409]: |undefined|fax_smtp:211 (<0.8837.0>) terminate {badarg,[{erlang,list_to_float,["2376\n"],[]},{wh_util,to_integer,2,[{file,"src/wh_util.erl"},{line,743}]},{fax_smtp,maybe_process_image,4,[{file,"src/fax_smtp.erl"},{line,779}]},{fax_smtp,process_parts,2,[{file,"src/fax_smtp.erl"},{line,672}]},{fax_smtp,handle_DATA,4,[{file,"src/fax_smtp.erl"},{line,143}]},{gen_smtp_server_session,handle_info,2,[{file,"src/gen_smtp_server_session.erl"},{line,190}]},{gen_server,handle_msg,5,[{file,"gen_server.erl"},{line,607}]},{proc_lib,init_p_do_apply,3,[{file,"proc_lib.erl"},{line,227}]}]}

Oct  5 04:40:29 kz 2600hz[5409]: |0000000000|Undefined:Undefined (<0.8837.0>) gen_server <0.8837.0> terminated with reason: bad argument in call to erlang:list_to_float("2376\n") in wh_util:to_integer/2 line 743

Oct  5 04:40:29 kz 2600hz[5409]: |0000000000|Undefined:Undefined (<0.8837.0>) CRASH REPORT Process <0.8837.0> with 0 neighbours exited with reason: bad argument in call to erlang:list_to_float("2376\n") in wh_util:to_integer/2 line 743 in gen_server:terminate/6 line 747

------------------ and sometimes this message also.  

Oct  5 05:13:48 kz 2600hz[5409]: |undefined|fax_smtp:651 (<0.18344.0>) processing multiple parts, first is text/plain

Oct  5 05:13:48 kz 2600hz[5409]: |undefined|fax_smtp:701 (<0.18344.0>) ignoring part text/plain

Oct  5 05:13:48 kz 2600hz[5409]: |undefined|fax_smtp:707 (<0.18344.0>) part is image/tiff

Oct  5 05:13:48 kz 2600hz[5409]: |undefined|fax_smtp:211 (<0.18344.0>) terminate {{badmatch,[<<"180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200\n">>]},[{fax_smtp,maybe_process_image,4,[{file,"src/fax_smtp.erl"},{line,777}]},{fax_smtp,process_parts,2,[{file,"src/fax_smtp.erl"},{line,672}]},{fax_smtp,handle_DATA,4,[{file,"src/fax_smtp.erl"},{line,143}]},{gen_smtp_server_session,handle_info,2,[{file,"src/gen_smtp_server_session.erl"},{line,190}]},{gen_server,handle_msg,5,[{file,"gen_server.erl"},{line,607}]},{proc_lib,init_p_do_apply,3,[{file,"proc_lib.erl"},{line,227}]}]}

Oct  5 05:13:48 kz 2600hz[5409]: |0000000000|Undefined:Undefined (<0.18344.0>) gen_server <0.18344.0> terminated with reason: no match of right hand value [<<"180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200\n">>] in fax_smtp:maybe_process_image/4 line 777

Oct  5 05:13:48 kz 2600hz[5409]: |0000000000|Undefined:Undefined (<0.18344.0>) CRASH REPORT Process <0.18344.0> with 0 neighbours exited with reason: no match of right hand value [<<"180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200180">>,<<"200\n">>] in fax_smtp:maybe_process_image/4 line 777 in gen_server:terminate/6 line 747

Oct  5 05:13:48 kz 2600hz[5409]: |whistle_couch_cache|wh_cache:652 (<0.851.0>) removed 1 objects

Sending an attachment with a PDF does work successfully how ever, it seems to just be with .tiff. Notably I have tried other types on the allowed list such as image/jpeg but receive a "no valid attachment" which is another issue all together.

Is anyone else having this error on 3.21?

Thank you all. 

[Luis Azedo]

Hi,

this seems to be a BUG. can you post the entire smtp envelope ?

tiff files should not be converted.

Best

--
You received this message because you are subscribed to the Google Groups "2600hz-dev" group.
To unsubscribe from this group and stop receiving emails from it, send an email to 2600hz-dev+...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[Luis Azedo]

can you also check if you have the "identify" command available ?

[VCCS Telecom]

Thanks for the quick reply Luis. I do have the identify command verified, and gs. 

Is there something from the SMTP envelope that you're looking for? If its the log you mean there isnt much there I can see, postfix processes first and it hits kazoo on 19025 and thats where it crashes. The couch doc has conversion_command

and pdf conversion command , I could try removing the regular conversion command entry but I was thinking that "identify" is supposed to to detect and circumvent that.

I also see issues with doc/docx but I think that's for another day, resulting in:

Oct  5 18:36:49 kz 2600hz[5409]: |undefined|fax_smtp:132 (<0.21035.7>) Handle Data From <<"m...@email.com">> to [<<"tel#@domain">>]

Oct  5 18:36:49 kz 2600hz[5409]: |undefined|fax_smtp:142 (<0.21035.7>) Message decoded successfully!

Oct  5 18:36:49 kz 2600hz[5409]: |undefined|fax_smtp:641 (<0.21035.7>) processing multipart/mixed

Oct  5 18:36:49 kz 2600hz[5409]: |undefined|fax_smtp:651 (<0.21035.7>) processing multiple parts, first is text/plain

Oct  5 18:36:49 kz 2600hz[5409]: |undefined|fax_smtp:701 (<0.21035.7>) ignoring part text/plain

Oct  5 18:36:49 kz 2600hz[5409]: |undefined|fax_smtp:707 (<0.21035.7>) part is application/vnd.openxmlformats-officedocument.wordprocessingml.document

Oct  5 18:36:49 kz 2600hz[5409]: |00000000000|wh_amqp_channel:154 (<0.629.0>) published to configuration(amqp://guest:guest@kz:5672) exchange (routing key doc_created.faxes.fax.25bc2cc1f00b5ab6a9960957ca6cb8a3) via <0.11659.0>

Oct  5 18:36:49 kz 2600hz[5409]: |00000000000|wh_amqp_worker:575 (<0.629.0>) published message undefined for <0.21062.7>

Oct  5 18:36:49 kz 2600hz[5409]: |undefined|couch_util:906 (<0.21059.7>) rev is in options list: [{headers,[{content_type,"application/vnd.openxmlformats-officedocument.wordprocessingml.document"}]},{rev,<<"1-9763456f4d7e1f6c0dfeb6081dccf43c">>}]

Oct  5 18:36:49 kz 2600hz[5409]: |whistle_couch_cache|wh_cache:447 (<0.851.0>) removed 0 objects for {couch_util,<<"faxes">>,<<"25bc2cc1f00b5ab6a9960957ca6cb8a3">>}

Oct  5 18:36:50 kz 2600hz[5409]: |00000000000|wh_amqp_channel:154 (<0.630.0>) published to configuration(amqp://guest:guest@kz:5672) exchange (routing key doc_edited.faxes.fax.25bc2cc1f00b5ab6a9960957ca6cb8a3) via <0.11663.0>

Oct  5 18:36:50 kz 2600hz[5409]: |00000000000|wh_amqp_worker:575 (<0.630.0>) published message undefined for <0.21075.7>

Oct  5 18:36:50 kz 2600hz[5409]: |whistle_couch_cache|wh_cache:447 (<0.851.0>) removed 0 objects for {couch_util,<<"faxes">>,<<"25bc2cc1f00b5ab6a9960957ca6cb8a3">>}

Oct  5 18:36:50 kz 2600hz[5409]: |undefined|fax_util:193 (<0.21059.7>) fax jobid 25bc2cc1f00b5ab6a9960957ca6cb8a3 set to pending

and this one has an email to follow as:

Error Sending Fax to {number}

Error : unknown error

Caller ID	{number we should have faxed to) (+{local faxbox number})
Callee ID	(originally dialed number)
Call received

[Luis Azedo]

Hi,

in 3.21 image/openoffice was added to fax and it seems that image is not working as it was before for tiff files. there also seems that openoffice has issues.

we are at KazooCon right now, i'll try to push an update till the end of the week.

stay tuned and sorry for this lost of functionality on the tiff files.

Best

[VCCS Telecom]

Thanks for checking into that Luis. 

Have a great conference and I hope to join you guys there one day, look forward to the slides.

Matt

[Luis Azedo]

Hi,

3.21-34 should fix the tiff / image files.

please test it and let us know.

Best

--

[VCCS Telecom]

Hey Luis, good news I have tested thoroughly that .tif and jpeg works now thank you! (also Office docs with some tweaking needed to disable the GUI it wants from the command, which I havent gotten to yet sorry)

I'm not sure if we are to be supporting .tiff but I am not able to send a successful .tiff yet, it doesn't like the header values resulting in this message: Error : Bad TIFF/F header - incorrect values in fields

The tiff2pdf command works when sending a CC of the fail running conversion command: tiff2pdf -o /tmp/22f1ce46255dfc40.pdf /tmp/22f1ce46255dfc40.tif &> /dev/null && echo -n "success" and I can view the pdf just fine, so I think it may lye in the detection command? Oddly though the conversion command used a .tif extension successfully but the file sent was a .tiff...The values seem off too as debug shows 32 pages of a tiff thats a small embedded image.

5d5ef1e298a14a1c 2015-10-10 18:38:08.997792 [DEBUG] mod_spandsp_fax.c:525 Fax processing not successful - result (46) Bad TIFF/F header - incorrect values in fields.

5d5ef1e298a14a1c 2015-10-10 18:38:08.997792 [DEBUG] mod_spandsp_fax.c:530 Remote station id: unknown

5d5ef1e298a14a1c 2015-10-10 18:38:08.997792 [DEBUG] mod_spandsp_fax.c:531 Local station id:  +1 (514) 555-5555

5d5ef1e298a14a1c 2015-10-10 18:38:08.997792 [DEBUG] mod_spandsp_fax.c:532 Pages transferred: 0

5d5ef1e298a14a1c 2015-10-10 18:38:08.997792 [DEBUG] mod_spandsp_fax.c:534 Total fax pages:   32

5d5ef1e298a14a1c 2015-10-10 18:38:08.997792 [DEBUG] mod_spandsp_fax.c:535 Image resolution:  0x0

5d5ef1e298a14a1c 2015-10-10 18:38:08.997792 [DEBUG] mod_spandsp_fax.c:536 Transfer Rate:     14400

5d5ef1e298a14a1c 2015-10-10 18:38:08.997792 [DEBUG] mod_spandsp_fax.c:538 ECM status         on

5d5ef1e298a14a1c 2015-10-10 18:38:08.997792 [DEBUG] mod_spandsp_fax.c:539 remote country:

5d5ef1e298a14a1c 2015-10-10 18:38:08.997792 [DEBUG] mod_spandsp_fax.c:540 remote vendor:

5d5ef1e298a14a1c 2015-10-10 18:38:08.997792 [DEBUG] mod_spandsp_fax.c:541 remote model:

5d5ef1e298a14a1c 2015-10-10 18:38:08.997792 [DEBUG] mod_spandsp_fax.c:543 ==============================================================================

Thanks again!

On Monday, October 5, 2015 at 12:56:41 PM UTC-4, VCCS Telecom wrote:

[Luis Azedo]

Hi,

Thanks for trying this and reporting back.

tif and tiff are the same, they should behave the same way, there should be no conversion involved in fax_smtp (getting the attachment from email) and in fax_worker (sending the fax).

can you check the kazoo logs and see if there was any conversion involved when using tif / tiff files?

Thanks

--

[VCCS Telecom]

Hi, there's no conversion attempt:

Oct 10 18:12:03 kz 2600hz[31696]: |undefined|fax_smtp:144 (<0.30114.0>) Message decoded successfully!

Oct 10 18:12:03 kz 2600hz[31696]: |undefined|fax_smtp:643 (<0.30114.0>) processing multipart/mixed

Oct 10 18:12:03 kz 2600hz[31696]: |undefined|fax_smtp:653 (<0.30114.0>) processing multiple parts, first is text/plain

Oct 10 18:12:03 kz 2600hz[31696]: |undefined|fax_smtp:705 (<0.30114.0>) ignoring part text/plain

Oct 10 18:12:03 kz 2600hz[31696]: |undefined|fax_smtp:711 (<0.30114.0>) part is image/tiff

Oct 10 18:12:04 kz 2600hz[31696]: |00000000000|wh_amqp_channel:154 (<0.462.0>) published to configuration(amqp://guest:guest@kz:5672) exchange (routing key doc_created.faxes.fax.535e121e64402c5803f7732b8136c9a0) via <0.1017.0>

Oct 10 18:12:04 kz 2600hz[31696]: |00000000000|wh_amqp_worker:575 (<0.462.0>) published message undefined for <0.30138.0>

Oct 10 18:12:04 kz 2600hz[31696]: |undefined|couch_util:906 (<0.30131.0>) rev is in options list: [{headers,[{content_type,"image/tiff"}]},{rev,<<"1-1b5ccebb487cabcdcc33a496b29ad3f1">>}]

Oct 10 18:12:04 kz 2600hz[31696]: |whistle_couch_cache|wh_cache:447 (<0.1071.0>) removed 0 objects for {couch_util,<<"faxes">>,<<"535e121e64402c5803f7732b8136c9a0">>}

"Error : Bad TIFF/F header - incorrect values in fields"

I have tried a few different files in case they were corrupted but had the same result, the only thing about .tiff opposed to .tif is the size seems to be quite larger. Otherwise I dont see what's what. I can provide my test files or if you have one that I can test with to be sure I will use it.

Also on an attempt to send 2 different .tif files with 1 page I received "Error : Far end cannot receive at the resolution of the image" , maybe that can be blamed on the Carrier, im not sure. FS says  Image resolution is 0x0... I have had other .tif's that have worked though. Troubleshooting this is a bit beyond me sorry..

Thanks.

[VCCS Telecom]

Just to update. Whether the Tiff is sent via email or scanned as a tiff image, sending results in "Error : Bad TIFF/F header - incorrect values in fields". Could it be in the conversion command of : usr/bin/gs -q -r204x98 -g1728x1078 ?

Fax processing not successful - result (46) Bad TIFF/F header - incorrect values in fields.

2015-10-16 18:22:39.393571 [DEBUG] mod_spandsp_fax.c:530 Remote station id: unknown

2015-10-16 18:22:39.393571 [DEBUG] mod_spandsp_fax.c:531 Local station id:  +1 (514) 555-5555

2015-10-16 18:22:39.393571 [DEBUG] mod_spandsp_fax.c:532 Pages transferred: 0

2015-10-16 18:22:39.393571 [DEBUG] mod_spandsp_fax.c:534 Total fax pages:   32

2015-10-16 18:22:39.393571 [DEBUG] mod_spandsp_fax.c:535 Image resolution:  0x0

2015-10-16 18:22:39.393571 [DEBUG] mod_spandsp_fax.c:536 Transfer Rate:     14400

2015-10-16 18:22:39.393571 [DEBUG] mod_spandsp_fax.c:538 ECM status         off

2015-10-16 18:22:39.393571 [DEBUG] mod_spandsp_fax.c:539 remote country:

2015-10-16 18:22:39.393571 [DEBUG] mod_spandsp_fax.c:540 remote vendor:

2015-10-16 18:22:39.393571 [DEBUG] mod_spandsp_fax.c:541 remote model:

Oddly it shows 32 pages ...

On Monday, October 5, 2015 at 12:56:41 PM UTC-4, VCCS Telecom wrote:

[Luis Azedo]

Hi,

there shouldn't be a convert command. 

do you have the kazoo logs that show the conversion ?

--

[VCCS Telecom]

Hi Luis, youre right sorry. I have enabled spandsp debugging and found the error hook. It looks like the fax out tries to use T30 and the error message is below. Using a physical Fax machine works perfectly (as it uses t38), it's only while sending a tif or jpeg via Email-to-Fax that fails with this.

2015-10-19 18:02:15.672534 [DEBUG] mod_spandsp_fax.c:334 === Negotiation Result =======================================================

2015-10-19 18:02:15.672534 [DEBUG] mod_spandsp_fax.c:335 Remote station id: unknown

2015-10-19 18:02:15.672534 [DEBUG] mod_spandsp_fax.c:336 Local station id:  +1 (514) xxx-xxxx

2015-10-19 18:02:15.672534 [DEBUG] mod_spandsp_fax.c:337 Transfer Rate:     14400

2015-10-19 18:02:15.672534 [DEBUG] mod_spandsp_fax.c:339 ECM status         off

2015-10-19 18:02:15.672534 [DEBUG] mod_spandsp_fax.c:340 remote country:

2015-10-19 18:02:15.672534 [DEBUG] mod_spandsp_fax.c:341 remote vendor:

2015-10-19 18:02:15.672534 [DEBUG] mod_spandsp_fax.c:342 remote model:

2015-10-19 18:02:15.672534 [DEBUG] mod_spandsp_fax.c:344 ==============================================================================

2015-10-19 18:02:15.672534 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Trying to send file '/usr/share/freeswitch/http_cache/81/8f00a6-768b-11e5-9202-8baed1df96a1.tiff'

2015-10-19 18:02:15.672534 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Start sending document

2015-10-19 18:02:15.672534 [WARNING] mod_spandsp_fax.c:293 WARNING T.30 Cannot negotiate an image format

2015-10-19 18:02:15.672534 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Status changing to 'Bad TIFF/F header - incorrect values in fields'

2015-10-19 18:02:15.672534 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Flushing queued phase B_TX

2015-10-19 18:02:15.672534 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Queuing phase D_TX

2015-10-19 18:02:15.672534 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Changing from state T to C

2015-10-19 18:02:15.672534 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Tx:  DCN with final frame tag

2015-10-19 18:02:15.672534 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Tx:  ff 13 fb

2015-10-19 18:02:15.672534 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 HDLC signal status is Carrier down (-1) in state C

2015-10-19 18:02:15.672534 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Changing from phase B_RX to D_TX

2015-10-19 18:02:15.672534 [DEBUG] mod_spandsp_fax.c:293 FLOW T.38T Set rx type 0

2015-10-19 18:02:15.672534 [DEBUG] mod_spandsp_fax.c:293 FLOW T.38T Set tx type 4

2015-10-19 18:02:15.672534 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 No signal is present

2015-10-19 18:02:16.852544 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Send complete in phase D_TX, state C

2015-10-19 18:02:16.852544 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Send complete in phase D_TX, state C

2015-10-19 18:02:16.852544 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Starting final pause before disconnecting

2015-10-19 18:02:16.852544 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Changing from phase D_TX to E

2015-10-19 18:02:16.852544 [DEBUG] mod_spandsp_fax.c:293 FLOW T.38T Set rx type 0

2015-10-19 18:02:16.852544 [DEBUG] mod_spandsp_fax.c:293 FLOW T.38T Set tx type 1

2015-10-19 18:02:16.852544 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Changing from state C to B

So far I can't see why t30 is being used... Thanks again.

On Monday, October 5, 2015 at 12:56:41 PM UTC-4, VCCS Telecom wrote:

[Luis Azedo]

Hi,

the use of T30 or T38 depends on your carrier and/or final destination.

can you check if the file /usr/share/freeswitch/http_cache/81/8f00a6-768b-11e5-9202-8baed1df96a1.tiff from your freeswitch server is valid ?

things that may be happening here

1) we are still converting after the fix when we shouldn't

2) you are retrying an old fax which was converted (prior to fix) and the file is still in freeswitch cache with invalid format.

Best

--

[VCCS Telecom]

Interesting.. I can negotiation T38 from the Carrier, also I'm sending a new fax on every test so it isn't cached. Also there isn't any conversion once kazoo sees the tiff format. I sometimes get the "Far end cant receive image of this size" but I use the default tif file included with the windows fax and scan app, as well as tif samples from online. Here is a full FS log:

v=0

o=FreeSWITCH 1445247383 1445247385 IN IP4 FS-IP

s=FreeSWITCH

c=IN IP4 FS-IP

t=0 0

m=image 32488 udptl t38

a=T38FaxVersion:0

a=T38MaxBitRate:14400

a=T38FaxFillBitRemoval

a=T38FaxRateManagement:transferredTCF

a=T38FaxMaxBuffer:2000

a=T38FaxMaxDatagram:400

a=T38FaxUdpEC:t38UDPRedundancy

2015-10-19 18:37:55.973547 [DEBUG] sofia_glue.c:1232 sofia/sipinterface_1/8555555555@provider sending invite version: 1.4.15  64bit

Local SDP:

v=0

o=FreeSWITCH 1445247383 1445247385 IN IP4 FS-IP

s=FreeSWITCH

c=IN IP4 FS-IP

t=0 0

m=image 32488 udptl t38

a=T38FaxVersion:0

a=T38MaxBitRate:14400

a=T38FaxFillBitRemoval

a=T38FaxRateManagement:transferredTCF

a=T38FaxMaxBuffer:2000

a=T38FaxMaxDatagram:400

a=T38FaxUdpEC:t38UDPRedundancy

2015-10-19 18:37:55.973547 [DEBUG] switch_core_session.c:1053 Send signal sofia/sipinterface_1/8555555555@provider [BREAK]

2015-10-19 18:37:55.973547 [DEBUG] sofia.c:6614 Channel sofia/sipinterface_1/8555555555@provider entering state [calling][0]

2015-10-19 18:37:56.033550 [DEBUG] switch_core_session.c:1053 Send signal sofia/sipinterface_1/8555555555@provider [BREAK]

2015-10-19 18:37:56.033550 [DEBUG] switch_core_session.c:1053 Send signal sofia/sipinterface_1/8555555555@provider [BREAK]

2015-10-19 18:37:56.053556 [DEBUG] sofia.c:6614 Channel sofia/sipinterface_1/8555555555@provider entering state [completing][200]

2015-10-19 18:37:56.053556 [DEBUG] sofia.c:6624 Remote SDP:

v=0

o=Sansay-VSXi 188 2 IN IP4 provider

s=Session Controller

c=IN IP4 4.55.xx.x

t=0 0

m=image 21016 udptl t38

a=T38FaxVersion:0

a=T38MaxBitRate:14400

a=T38FaxRateManagement:transferredTCF

a=T38FaxMaxBuffer:262

a=T38FaxMaxDatagram:176

a=T38FaxUdpEC:t38UDPRedundancy

2015-10-19 18:37:56.053556 [DEBUG] switch_core_session.c:1053 Send signal sofia/sipinterface_1/8555555555@provider [BREAK]

2015-10-19 18:37:56.053556 [DEBUG] switch_core_session.c:1053 Send signal sofia/sipinterface_1/8555555555@provider [BREAK]

2015-10-19 18:37:56.053556 [DEBUG] sofia.c:6614 Channel sofia/sipinterface_1/8555555555@provider entering state [ready][200]

2015-10-19 18:37:56.053556 [DEBUG] switch_core_media.c:7719 Remote address:port [4.55.xx.x:21016] has not changed.

2015-10-19 18:37:56.053556 [DEBUG] switch_core_media.c:7719 Remote address:port [4.55.xx.x:21016] has not changed.

2015-10-19 18:37:56.053556 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 No signal is present

2015-10-19 18:38:02.213565 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 A signal is present

2015-10-19 18:38:02.213565 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 HDLC signal status is Carrier up (-2) in state T

2015-10-19 18:38:02.213565 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 HDLC signal status is Framing OK (-6) in state T

2015-10-19 18:38:02.213565 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Changing from phase A_CNG to B_RX

2015-10-19 18:38:02.213565 [DEBUG] mod_spandsp_fax.c:293 FLOW T.38T Set rx type 4

2015-10-19 18:38:02.213565 [DEBUG] mod_spandsp_fax.c:293 FLOW T.38T Set tx type 0

2015-10-19 18:38:03.853568 [DEBUG] mod_spandsp_fax.c:293 FLOW T.38T Type CSI - CRC OK (clean)

2015-10-19 18:38:03.853568 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Stop none (0 remaining)

2015-10-19 18:38:03.853568 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Rx:  CSI without final frame tag

2015-10-19 18:38:03.853568 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Rx:  ff 03 40 6e 77 6f 6e 6b 6e 75 20 20 20 20 20 20 20 20 20 20 20 20 20

2015-10-19 18:38:03.853568 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Remote gave CSI as: "unknown"

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.38T Type DIS - CRC OK, sig end (clean)

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Stop none (0 remaining)

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Rx:  DIS with final frame tag

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Rx:  ff 13 80 00 ee f8 80 80 91 80 80 80 18

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Rx final frame in state T

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Queuing phase B_TX

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 DIS:

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .... ...0= Store and forward Internet fax (T.37): Not set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .... .0..= Real-time Internet fax (T.38): Not set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .... 0...= 3G mobile network: Not set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   ..0. ....= V.8 capabilities: Not set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .0.. ....= Preferred octets: 256 octets

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .... ...0= Ready to transmit a fax document (polling): Not set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .... ..1.= Can receive fax: Set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   ..10 11..= Supported data signalling rates: V.27 ter, V.29, and V.17

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .1.. ....= R8x7.7lines/mm and/or 200x200pels/25.4mm: Set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   1... ....= 2-D coding: Set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .... ..00= Recording width: 215mm +- 1%

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .... 10..= Recording length: Unlimited

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .111 ....= Receiver's minimum scan line time: 0ms at 3.85 l/mm; T7.7 = T3.85

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   1... ....= Extension indicator: Set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .... ..0.= Compressed/uncompressed mode: Compressed

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .... .0..= Error correction mode (ECM): Non-ECM

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .0.. ....= T.6 coding: Not set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   1... ....= Extension indicator: Set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .... ...0= "Field not valid" supported: Not set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .... ..0.= Multiple selective polling: Not set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .... .0..= Polled sub-address: Not set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .... 0...= T.43 coding: Not set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   ...0 ....= Plane interleave: Not set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   ..0. ....= Voice coding with 32kbit/s ADPCM (Rec. G.726): Not set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .0.. ....= Reserved for the use of extended voice coding set: Not set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   1... ....= Extension indicator: Set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .... ...1= R8x15.4lines/mm: Set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .... ..0.= 300x300pels/25.4mm: Not set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .... .0..= R16x15.4lines/mm and/or 400x400pels/25.4mm: Not set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .... 0...= Inch-based resolution preferred: Not set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   ...1 ....= Metric-based resolution preferred: Set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   ..0. ....= Minimum scan line time for higher resolutions: T15.4 = T7.7

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .0.. ....= Selective polling: Not set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   1... ....= Extension indicator: Set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .... ...0= Sub-addressing: Not set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .... ..0.= Password: Not set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .... .0..= Ready to transmit a data file (polling): Not set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   ...0 ....= Binary file transfer (BFT): Not set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   ..0. ....= Document transfer mode (DTM): Not set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .0.. ....= Electronic data interchange (EDI): Not set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   1... ....= Extension indicator: Set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .... ...0= Basic transfer mode (BTM): Not set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .... .0..= Ready to transfer a character or mixed mode document (polling): Not set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .... 0...= Character mode: Not set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   ..0. ....= Mixed mode (Annex E/T.4): Not set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   1... ....= Extension indicator: Set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .... ...0= Processable mode 26 (Rec. T.505): Not set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .... ..0.= Digital network capability: Not set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .... .0..= Duplex capability: Half only

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .... 0...= JPEG coding: Not set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   ...0 ....= Full colour mode: Not set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .0.. ....= 12bits/pel component: Not set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   1... ....= Extension indicator: Set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .... ...0= No subsampling (1:1:1): Not set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .... ..0.= Custom illuminant: Not set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .... .0..= Custom gamut range: Not set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .... 1...= North American Letter (215.9mm x 279.4mm): Set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   ...1 ....= North American Legal (215.9mm x 355.6mm): Set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   ..0. ....= Single-progression sequential coding (Rec. T.85) basic: Not set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   .0.. ....= Single-progression sequential coding (Rec. T.85) optional L0: Not set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30   0... ....= Extension indicator: Not set

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:334 === Negotiation Result =======================================================

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:335 Remote station id: unknown

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:336 Local station id:  +1 (514) xxx-xxxx

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:337 Transfer Rate:     14400

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:339 ECM status         off

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:340 remote country:

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:341 remote vendor:

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:342 remote model:

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:344 ==============================================================================

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Trying to send file '/usr/share/freeswitch/http_cache/82/339468-7690-11e5-b71c-ffa3c10b9591.tiff'

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Start sending document

2015-10-19 18:38:04.293569 [WARNING] mod_spandsp_fax.c:293 WARNING T.30 Cannot negotiate an image format

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Status changing to 'Bad TIFF/F header - incorrect values in fields'

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Flushing queued phase B_TX

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Queuing phase D_TX

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Changing from state T to C

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Tx:  DCN with final frame tag

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Tx:  ff 13 fb

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 HDLC signal status is Carrier down (-1) in state C

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Changing from phase B_RX to D_TX

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.38T Set rx type 0

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.38T Set tx type 4

2015-10-19 18:38:04.293569 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 No signal is present

2015-10-19 18:38:05.473547 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Send complete in phase D_TX, state C

2015-10-19 18:38:05.473547 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Send complete in phase D_TX, state C

2015-10-19 18:38:05.473547 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Starting final pause before disconnecting

2015-10-19 18:38:05.473547 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Changing from phase D_TX to E

2015-10-19 18:38:05.473547 [DEBUG] mod_spandsp_fax.c:293 FLOW T.38T Set rx type 0

2015-10-19 18:38:05.473547 [DEBUG] mod_spandsp_fax.c:293 FLOW T.38T Set tx type 1

2015-10-19 18:38:05.473547 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Changing from state C to B

/exit2015-10-19 18:38:06.793552 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Send complete in phase E, state B

2015-10-19 18:38:06.793552 [DEBUG] mod_spandsp_fax.c:513 ==============================================================================

2015-10-19 18:38:06.793552 [DEBUG] mod_spandsp_fax.c:525 Fax processing not successful - result (46) Bad TIFF/F header - incorrect values in fields.

2015-10-19 18:38:06.793552 [DEBUG] mod_spandsp_fax.c:530 Remote station id: unknown

2015-10-19 18:38:06.793552 [DEBUG] mod_spandsp_fax.c:531 Local station id:  +1 (514) xxx-xxxx

2015-10-19 18:38:06.793552 [DEBUG] mod_spandsp_fax.c:532 Pages transferred: 0

2015-10-19 18:38:06.793552 [DEBUG] mod_spandsp_fax.c:534 Total fax pages:   1

2015-10-19 18:38:06.793552 [DEBUG] mod_spandsp_fax.c:535 Image resolution:  0x0

2015-10-19 18:38:06.793552 [DEBUG] mod_spandsp_fax.c:536 Transfer Rate:     14400

2015-10-19 18:38:06.793552 [DEBUG] mod_spandsp_fax.c:538 ECM status         off

2015-10-19 18:38:06.793552 [DEBUG] mod_spandsp_fax.c:539 remote country:

2015-10-19 18:38:06.793552 [DEBUG] mod_spandsp_fax.c:540 remote vendor:

2015-10-19 18:38:06.793552 [DEBUG] mod_spandsp_fax.c:541 remote model:

2015-10-19 18:38:06.793552 [DEBUG] mod_spandsp_fax.c:543 ==============================================================================

2015-10-19 18:38:06.793552 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Changing from state B to CALL_FINISHED

2015-10-19 18:38:06.793552 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Changing from phase E to CALL_FINISHED

2015-10-19 18:38:06.793552 [DEBUG] mod_spandsp_fax.c:293 FLOW T.38T Set rx type 9

2015-10-19 18:38:06.793552 [DEBUG] mod_spandsp_fax.c:293 FLOW T.38T Set tx type 9

2015-10-19 18:38:06.793552 [DEBUG] mod_spandsp_fax.c:293 FLOW T.38T FAX exchange complete

2015-10-19 18:38:06.793552 [DEBUG] mod_spandsp_fax.c:293 FLOW T.30 Call completed

2015-10-19 18:38:08.113559 [DEBUG] switch_core_session.c:1053 Send signal sofia/sipinterface_1/8555555555@provider [BREAK]

2015-10-19 18:38:08.113559 [DEBUG] switch_core_codec.c:246 sofia/sipinterface_1/8555555555@provider Restore previous codec PCMU:0.

2015-10-19 18:38:08.113559 [NOTICE] sofia.c:952 Hangup sofia/sipinterface_1/8555555555@provider [CS_EXECUTE] [NORMAL_CLEARING]

On Monday, October 5, 2015 at 12:56:41 PM UTC-4, VCCS Telecom wrote:

[Luis Azedo]

Thank for looking into this.

can you get the file from freeswitch /usr/share/freeswitch/http_cache/82/339468-7690-11e5-b71c-ffa3c10b9591.tiff and open it in windows ?

--

[VCCS Telecom]

It's view-able yes.. 

I noticed that the folder/file permissions are 750 so I did a test with increasing the rights for the FS user but only on the http_cache folder itself, with the same results. Would you think the perms on the sub folder or file would matter? Since FS is the owner I don't see why... 

Also this occurs when converting from word docs as well using "Internet Fax" for what its worth..

If you have a known valid tif file I can test with, I'd be happy to.

Thanks again.