[asterisk-users] Asterisk core dumping on SendFax with FFA
Ben Dinnerville
ben at voicelogic.com.au
Wed May 12 08:12:48 CDT 2010
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
More information about the asterisk-users
mailing list