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
[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.pdfIt 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
[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
[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.