thr3ads.net - asterisk users - [asterisk-users] Asterisk core dumping on SendFax with FFA [May 2010]

If this information is useful, please help other people find it:
Share via:

Ben Dinnerville

2010-May-12 13:12 UTC

[asterisk-users] Asterisk core dumping on SendFax with FFA

Hi All,

I seem to have stumbled on a bit of a problem. When trying to send a fax 
with Fax For Asterisk on 1.6.2.x (have tried 1.6.2.5, 1.6.2.7 and the 
current svn version, with FFA 1.2 I get a core dump each time.

Here is an extract form the console:

[May 12 22:47:09] DEBUG[22584]: app_queue.c:1084 handle_statechange: 
Device 'SIP/vltb-sbc01' changed to state '1' (Not in use) but we
don't
care because they're not a member of any queue.
[May 12 22:47:09] DEBUG[22725]: pbx.c:3692 pbx_extension_helper: 
Launching 'Set'
     -- Executing [s at tbsendfax:1] Set("SIP/vltb-sbc01-00000000", 
"timestarted=20100512224709") in new stack
[May 12 22:47:09] DEBUG[22725]: pbx.c:3692 pbx_extension_helper: 
Launching 'Answer'
     -- Executing [s at tbsendfax:2] Answer("SIP/vltb-sbc01-00000000",
"")
in new stack
[May 12 22:47:09] DEBUG[22725]: pbx.c:3692 pbx_extension_helper: 
Launching 'Set'
     -- Executing [s at tbsendfax:3] Set("SIP/vltb-sbc01-00000000", 
"ANSWERED=1") in new stack
[May 12 22:47:09] DEBUG[22725]: pbx.c:3692 pbx_extension_helper: 
Launching 'Set'
     -- Executing [s at tbsendfax:4] Set("SIP/vltb-sbc01-00000000", 
"CALLSTATUS=0") in new stack
[May 12 22:47:09] DEBUG[22725]: pbx.c:3692 pbx_extension_helper: 
Launching 'Set'
     -- Executing [s at tbsendfax:5] Set("SIP/vltb-sbc01-00000000", 
"FAXOPT(localstationid)="vltbfax"") in new stack
[May 12 22:47:09] DEBUG[22725]: res_fax.c:2120 acf_faxopt_write: channel 
'SIP/vltb-sbc01-00000000' setting FAXOPT(localstationid) to
'"vltbfax"'
[May 12 22:47:09] DEBUG[22725]: pbx.c:3692 pbx_extension_helper: 
Launching 'Set'
     -- Executing [s at tbsendfax:6] Set("SIP/vltb-sbc01-00000000", 
"FAXOPT(ecm)=no") in new stack
[May 12 22:47:09] DEBUG[22725]: res_fax.c:2120 acf_faxopt_write: channel 
'SIP/vltb-sbc01-00000000' setting FAXOPT(ecm) to 'no'
[May 12 22:47:09] DEBUG[22725]: pbx.c:3692 pbx_extension_helper: 
Launching 'SendFAX'
     -- Executing [s at tbsendfax:7]
SendFAX("SIP/vltb-sbc01-00000000",
"/var/spool/asterisk/fax/campaign_70.tif") in new stack
     -- Channel 'SIP/vltb-sbc01-00000000' sending FAX 
'/var/spool/asterisk/fax/campaign_70.tif'
[May 12 22:47:09] DEBUG[22725]: channel.c:2434 ast_settimeout: 
Scheduling timer at (50 requested / 50 actual) timer ticks per second
[May 12 22:47:09] DEBUG[22725]: channel.c:2548 
ast_read_generator_actions: Generator got voice, switching to phase 
locked mode
[May 12 22:47:09] DEBUG[22725]: channel.c:2434 ast_settimeout: 
Scheduling timer at (0 requested / 0 actual) timer ticks per second
[May 12 22:47:09] DEBUG[22725]: rtp.c:3878 ast_rtp_write: Ooh, format 
changed from unknown to alaw
[May 12 22:47:09] DEBUG[22725]: rtp.c:3904 ast_rtp_write: Created 
smoother: format: 8 ms: 20 len: 160
[May 12 22:47:13] DEBUG[22725]: rtp.c:1240 ast_rtcp_read: Got RTCP 
report of 88 bytes
[May 12 22:47:15] DEBUG[22587]: chan_sip.c:8223 process_sdp: Processing 
session-level SDP v=0... UNSUPPORTED.
[May 12 22:47:15] DEBUG[22587]: chan_sip.c:8223 process_sdp: Processing 
session-level SDP o=- 840372135 840372136 IN IP4 125.213.160.145... 
UNSUPPORTED.
[May 12 22:47:15] DEBUG[22587]: chan_sip.c:8223 process_sdp: Processing 
session-level SDP s=ENSResip... UNSUPPORTED.
[May 12 22:47:15] DEBUG[22587]: chan_sip.c:8223 process_sdp: Processing 
session-level SDP c=IN IP4 125.213.162.37... OK.
[May 12 22:47:15] DEBUG[22587]: chan_sip.c:8223 process_sdp: Processing 
session-level SDP t=0 0... UNSUPPORTED.
[May 12 22:47:15] DEBUG[22587]: chan_sip.c:8982 process_sdp_a_image: 
FaxVersion: 0
[May 12 22:47:15] DEBUG[22587]: chan_sip.c:8387 process_sdp: Processing 
media-level (image) SDP a=T38FaxVersion:0... OK.
[May 12 22:47:15] DEBUG[22587]: chan_sip.c:8959 process_sdp_a_image: 
T38MaxBitRate: 9600
[May 12 22:47:15] DEBUG[22587]: chan_sip.c:8387 process_sdp: Processing 
media-level (image) SDP a=T38MaxBitRate:9600... OK.
[May 12 22:47:15] DEBUG[22587]: chan_sip.c:8956 process_sdp_a_image: 
MaxBufferSize:200
[May 12 22:47:15] DEBUG[22587]: chan_sip.c:8387 process_sdp: Processing 
media-level (image) SDP a=T38FaxMaxBuffer:200... OK.
[May 12 22:47:15] DEBUG[22587]: chan_sip.c:8991 process_sdp_a_image: 
FaxMaxDatagram: 72
[May 12 22:47:15] DEBUG[22587]: chan_sip.c:8387 process_sdp: Processing 
media-level (image) SDP a=T38FaxMaxDatagram:72... OK.
[May 12 22:47:15] DEBUG[22587]: chan_sip.c:9028 process_sdp_a_image: 
RateManagement: transferredTCF
[May 12 22:47:15] DEBUG[22587]: chan_sip.c:8387 process_sdp: Processing 
media-level (image) SDP a=T38FaxRateManagement:transferredTCF... OK.
[May 12 22:47:15] DEBUG[22587]: chan_sip.c:9035 process_sdp_a_image: UDP 
EC: t38UDPRedundancy
[May 12 22:47:15] DEBUG[22587]: chan_sip.c:8387 process_sdp: Processing 
media-level (image) SDP a=T38FaxUdpEC:t38UDPRedundancy... OK.
[May 12 22:47:15] DEBUG[22587]: chan_sip.c:8996 process_sdp_a_image: 
FillBitRemoval: 0
[May 12 22:47:15] DEBUG[22587]: chan_sip.c:8387 process_sdp: Processing 
media-level (image) SDP a=T38FaxFillBitRemoval:0... OK.
[May 12 22:47:15] DEBUG[22587]: chan_sip.c:9007 process_sdp_a_image: 
Transcoding MMR: 0
[May 12 22:47:15] DEBUG[22587]: chan_sip.c:8387 process_sdp: Processing 
media-level (image) SDP a=T38FaxTranscodingMMR:0... OK.
[May 12 22:47:15] DEBUG[22587]: chan_sip.c:9018 process_sdp_a_image: 
Transcoding JBIG: 0
[May 12 22:47:15] DEBUG[22587]: chan_sip.c:8387 process_sdp: Processing 
media-level (image) SDP a=T38FaxTranscodingJBIG:0... OK.
[May 12 22:47:15] DEBUG[22587]: chan_sip.c:5034 change_t38_state: T38 
state changed to 2 on channel SIP/vltb-sbc01-00000000
[May 12 22:47:15] DEBUG[22587]: chan_sip.c:8586 process_sdp: Have T.38 
but no audio, accepting offer anyway
[May 12 22:47:15] DEBUG[22587]: chan_sip.c:20433 handle_request_invite: 
SIP/vltb-sbc01-00000000: This call is UP....
[May 12 22:47:15] DEBUG[22587]: chan_sip.c:3561 __sip_xmit: Trying to 
put 'SIP/2.0 100' onto UDP socket destined for 202.167.246.165:5060
[May 12 22:47:15] DEBUG[22725]: chan_sip.c:5034 change_t38_state: T38 
state changed to 3 on channel SIP/vltb-sbc01-00000000
[May 12 22:47:15] DEBUG[22725]: chan_sip.c:10410 add_sdp: Done building 
SDP. Settling with this capability: 0x0 (nothing)
[May 12 22:47:15] DEBUG[22725]: chan_sip.c:3561 __sip_xmit: Trying to 
put 'SIP/2.0 200' onto UDP socket destined for 202.167.246.165:5060
[May 12 22:47:15] DEBUG[22725]: channel.c:2434 ast_settimeout: 
Scheduling timer at (0 requested / 0 actual) timer ticks per second
[May 12 22:47:15] NOTICE[22725]: res_fax.c:1373 sendfax_t38_init: 
Negotiated T.38 for send on SIP/vltb-sbc01-00000000
[May 12 22:47:15] ERROR[22725]: res_fax_digium.c:2114 dgm_fax_start: FAX 
handle 0: failed to queue document
'/var/spool/asterisk/fax/campaign_70.tif'
[May 12 22:47:15] ERROR[22725]: res_fax.c:834 generic_fax_exec: channel 
'SIP/vltb-sbc01-00000000' FAX session '0' failure, reason:
'failed to
start FAX session'
[May 12 22:47:15] DEBUG[22587]: chan_sip.c:4097 __sip_ack: Stopping 
retransmission on '197593892ad59589494f1e56403b7586 at 202.177.217.102'
of
Response 100: Match Found
sp02*CLI>
Disconnected from Asterisk server
[root at sp02 tmp]# /usr/sbin/safe_asterisk: line 138: 22547 Segmentation 
fault      (core dumped) nice -n $PRIORITY ${ASTSBINDIR}/asterisk -f 
${CLIARGS} ${ASTARGS} >&/dev/${TTY} < /dev/${TTY}
Asterisk ended with exit status 139
Asterisk exited on signal 11.
cat: /var/run/asterisk.pid: No such file or directory
Automatically restarting Asterisk.



The system is running on Centos 5.2 i386 but I can also re-produce on 
Centos 5.4 x86_64

The issue seems to be with the error - "failed to queue document 
'/var/spool/asterisk/fax/campaign_70.tif'" However I can confirm
that a)
the file exists, b) it is worl readable and c) is created from a pdf 
with ghostscipt in the recommended fashion - gs -q -dNOPAUSE -dBATCH 
-sDEVICE=tiffg4 -sPAPERSIZE=a4 -sColorMode=mono 
-sOutputFile=campaign_70.tif combo2010.pdf

and can open the file in preview on mac without any issues.

There is no further information in the logs / console I cannot think of 
any other reason why it would not be able to queue the file.

Digium for some reason do not leave the older versions of FFA on their 
site so I am unable to test this on older versions of FFA, only older 
versions of asterisk all of which reproduce the same results (have tried 
asterisk-1.6.1.19.tar.gz
asterisk-1.6.2.2.tar.gz
asterisk-1.6.2.5.tar.gz
asterisk-1.6.2.7.tar.gz)

Anyone else having core dump issues or fax failure issues with 1.2.0? 
This one has kept me up for 2 days now - if I had any hair i would be 
pulling it out now.

Cheers,

Ben

Kevin P. Fleming

2010-May-12 13:32 UTC

head link

[asterisk-users] Asterisk core dumping on SendFax with FFA

On 05/12/2010 08:12 AM, Ben Dinnerville wrote:
> [May 12 22:47:15] ERROR[22725]: res_fax_digium.c:2114 dgm_fax_start: FAX 
> handle 0: failed to queue document
'/var/spool/asterisk/fax/campaign_70.tif'
> [May 12 22:47:15] ERROR[22725]: res_fax.c:834 generic_fax_exec: channel 
> 'SIP/vltb-sbc01-00000000' FAX session '0' failure, reason:
'failed to
> start FAX session'
This is a known bug, that is fixed in the FFA 1.2.1 release which is in
testing right now; if you contact Digium Support, they should be able to
get you a copy of it.
> The issue seems to be with the error - "failed to queue document 
> '/var/spool/asterisk/fax/campaign_70.tif'" However I can
confirm that a)
> the file exists, b) it is worl readable and c) is created from a pdf 
> with ghostscipt in the recommended fashion - gs -q -dNOPAUSE -dBATCH 
> -sDEVICE=tiffg4 -sPAPERSIZE=a4 -sColorMode=mono 
> -sOutputFile=campaign_70.tif combo2010.pdf
It would be helpful if you could provide that file to the support
technician so it can be investigated.
> Anyone else having core dump issues or fax failure issues with 1.2.0? 
> This one has kept me up for 2 days now - if I had any hair i would be 
> pulling it out now.
Like I said, it's a known problem, and the fix should be out within a
day or two. It was reported to us about a week ago, so if you had
contacted the support department, it's likely they would have been able
to shortcut your hair-pulling experience :-)

-- 
Kevin P. Fleming
Digium, Inc. | Director of Software Technologies
445 Jan Davis Drive NW - Huntsville, AL 35806 - USA
skype: kpfleming | jabber: kfleming at digium.com
Check us out at www.digium.com & www.asterisk.org

Ben Dinnerville

2010-May-13 01:53 UTC

head link

[asterisk-users] Asterisk core dumping on SendFax with FFA

Well, I have managed to get my hands on a copy of 1.2.1 rc1 FFA which 
seems to have fixed the core dumping issue but does not appear to have 
fixed the issue that was causing the core dump.

We are still getting an issue with a particular file which I have tried 
multiple different ways to create to no avail. The tiff file is created 
with ghostscript from a pdf as per the guidlines but every time we try 
and fax it we get the following:

[May 13 11:28:09] DEBUG[26959] res_fax_digium.c: FAX handle 0: created 
document queue
[May 13 11:28:09] ERROR[26959] res_fax_digium.c: FAX handle 0: failed to 
queue document '/var/spool/asterisk/fax/campaign_70.tif'
[May 13 11:28:09] DEBUG[26959] res_fax_digium.c: FAX handle 0: freeing 
document queue.
[May 13 11:28:09] DEBUG[26959] res_fax_digium.c: FAX handle 0: closing
[May 13 11:28:09] ERROR[26959] res_fax.c: channel 
'SIP/teleblast-sbc01-00000001' FAX session '1' failure, reason:
'failed
to start F
AX session'

and the call terminates.

tiffinfo for the file shows:

TIFF Directory at offset 0x2aae0 (174816)
   Subfile Type: multi-page document (2 = 0x2)
   Image Width: 1767 Image Length: 2369
   Resolution: 204, 196 pixels/inch
   Bits/Sample: 1
   Compression Scheme: CCITT Group 4
   Photometric Interpretation: min-is-white
   FillOrder: msb-to-lsb
   Orientation: row 0 top, col 0 lhs
   Samples/Pixel: 1
   Rows/Strip: 2369
   Planar Configuration: single image plane
   Page Number: 0-0
   Software: GPL Ghostscript 8.70
   DateTime: 2010:05:12 23:20:00
   Group 4 Options: (0 = 0x0)
TIFF Directory at offset 0x57172 (356722)
   Subfile Type: multi-page document (2 = 0x2)
   Image Width: 1767 Image Length: 2369
   Resolution: 204, 196 pixels/inch
   Bits/Sample: 1
   Compression Scheme: CCITT Group 4
   Photometric Interpretation: min-is-white
   FillOrder: msb-to-lsb
   Orientation: row 0 top, col 0 lhs
   Samples/Pixel: 1
   Rows/Strip: 2369
   Planar Configuration: single image plane
   Page Number: 1-0
   Software: GPL Ghostscript 8.70
   DateTime: 2010:05:12 23:20:11
   Group 4 Options: (0 = 0x0)


And the file is 357026 bytes in size. Can anyone see anything wrong with 
the tiff info or does anyone know of any issues with multiple pages or 
file size with fax for asterisk? Unfortunately I cannot seem to find any 
more information as to why the document couldn't be queued.

Cheers,

Ben

David Backeberg

2010-May-13 02:06 UTC

head link

[asterisk-users] Asterisk core dumping on SendFax with FFA

On Wed, May 12, 2010 at 9:53 PM, Ben Dinnerville <ben at
voicelogic.com.au> wrote:> We are still getting an issue with a particular file which I have tried
> multiple different ways to create to no avail. The tiff file is created
> with ghostscript from a pdf as per the guidlines but every time we try
> and fax it we get the following:
Try using ReceiveFax(),
and use a pdf=to-fax service or your own fax machine to fax it to your
asterisk machine.

That will give you an asterisk-created tiff of your pdf.

I used ReceiveFax() to generate the tiffs I use for SendFax() testing.

Seemingly Similar Threads

Search for more seemingly similar threads

asterisk users - May 2010 - Asterisk core dumping on SendFax with FFA

[asterisk-users] Asterisk core dumping on SendFax with FFA

[asterisk-users] Asterisk core dumping on SendFax with FFA

[asterisk-users] Asterisk core dumping on SendFax with FFA

[asterisk-users] Asterisk core dumping on SendFax with FFA

Seemingly Similar Threads