thr3ads.net - asterisk users - [Asterisk-Users] Asterisk spanDSP / Faxing problem [Mar 2006]

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

Thys de Wet

2006-Mar-25 04:56 UTC

[Asterisk-Users] Asterisk spanDSP / Faxing problem

Hi There.
I have the following setup :
Asterisk 1.2.4 , freePBX 2.0.1, spandsp-0.0.2pre24

My problem is as follows :
If I set up a very simple extensions.conf. when I dial from a fax 
machine, it seems as if no fax is being recognised.
If I answer the call, I can hear the fax machine beeping.



extensions.conf :
-----------------------------------------------------------------------------------------------------------
[from-pstn]
 ; Answer the line and listen
 exten => s,1,Answer
 ; Dial an extension, let asterisk give a ringtone
 exten => s,2,Dial(SIP/3000,40,r)
 ; Hangup if nobody picked up within 40 seconds
 exten => s,3,Hangup

 ; Did we get a fax?   <--------------------------Seems as if we never 
get this far :(((((
 exten => fax,1,SetVar(FAXFILE=/var/spool/asterisk-fax/${UNIQUEID}.tif)
 exten => fax,2,rxfax(${FAXFILE}|debug)
-------------------------------------------------------------------------------------------------------------
zapata.conf :
-------------------------------------------------------------------------------------------------------------
[trunkgroups]
; define any trunk groups
[channels]
; hardware channels
; default
usecallerid=yes
hidecallerid=no
callwaiting=no
threewaycalling=yes
transfer=yes
echocancel=yes
echotraining=yes

faxdetect=both
busydetect=yes
busycount=4
busypattern=500,500
callprogress=no


; define channels
context=from-pstn ;
signalling=fxs_ls ;
channel=>1-3 ;
 
context=aa_1 ;
signalling=fxs_ls ;
channel=>4 ;
--------------------------------------------------------------------------------------------------------------------------------------------------
Output from asterisk log :

Mar 25 13:45:16 VERBOSE[17282] logger.c:     -- Starting simple switch 
on 'Zap/1-1'
Mar 25 13:45:18 NOTICE[17282] chan_zap.c: Got event 18 (Ring Begin)...
Mar 25 13:45:19 NOTICE[17282] chan_zap.c: Got event 2 (Ring/Answered)...
Mar 25 13:45:21 NOTICE[17282] chan_zap.c: Got event 18 (Ring Begin)...
Mar 25 13:45:21 VERBOSE[17282] logger.c:     -- Executing 
Answer("Zap/1-1", "") in new stack
Mar 25 13:45:21 DEBUG[17282] chan_zap.c: Took Zap/1-1 off hook
Mar 25 13:45:21 DEBUG[17282] chan_zap.c: Enabled echo cancellation on 
channel 1
Mar 25 13:45:21 DEBUG[17282] chan_zap.c: Engaged echo training on channel 1
Mar 25 13:45:21 VERBOSE[17282] logger.c:     -- Executing 
Dial("Zap/1-1", "SIP/3000|40|r") in new stack
Mar 25 13:45:21 DEBUG[17282] chan_sip.c: Setting NAT on RTP to 0
Mar 25 13:45:21 DEBUG[17282] chan_sip.c: Outgoing Call for 3000
Mar 25 13:45:21 VERBOSE[17282] logger.c:     -- Called 3000
Mar 25 13:45:21 DEBUG[17282] chan_zap.c: Requested indication 3 on 
channel Zap/1-1
Mar 25 13:45:21 DEBUG[17229] chan_sip.c: (Provisional) Stopping 
retransmission (but retaining packet) on 
'5f8bf93a4e7e14fa4b9c2319609192c6@192.168.1.76' Request 102: Found
Mar 25 13:45:21 DEBUG[17229] chan_sip.c: (Provisional) Stopping 
retransmission (but retaining packet) on 
'5f8bf93a4e7e14fa4b9c2319609192c6@192.168.1.76' Request 102: Found
Mar 25 13:45:21 VERBOSE[17282] logger.c:     -- SIP/3000-dbc4 is ringing
Mar 25 13:45:21 DEBUG[17222] channel.c: Avoiding initial deadlock for 
'SIP/3000-dbc4'
Mar 25 13:45:29 DEBUG[17229] chan_sip.c: Acked pending invite 102
Mar 25 13:45:29 DEBUG[17229] chan_sip.c: Stopping retransmission on 
'5f8bf93a4e7e14fa4b9c2319609192c6@192.168.1.76' of Request 102: Match
Found
Mar 25 13:45:29 DEBUG[17229] chan_sip.c: build_route: Contact hop: 
<sip:3000@192.168.1.74>
Mar 25 13:45:29 VERBOSE[17282] logger.c:     -- SIP/3000-dbc4 answered 
Zap/1-1
Mar 25 13:45:29 DEBUG[17282] chan_zap.c: Requested indication -1 on 
channel Zap/1-1
Mar 25 13:45:50 DEBUG[17282] channel.c: Didn't get a frame from channel: 
SIP/3000-dbc4
Mar 25 13:45:50 DEBUG[17282] channel.c: Bridge stops bridging channels 
Zap/1-1 and SIP/3000-dbc4
Mar 25 13:45:50 DEBUG[17282] chan_sip.c: update_call_counter(3000) - 
decrement call limit counter
Mar 25 13:45:50 DEBUG[17282] app_dial.c: Exiting with DIALSTATUS=ANSWER.
Mar 25 13:45:50 VERBOSE[17282] logger.c:   == Spawn extension 
(from-pstn, s, 2) exited non-zero on 'Zap/1-1'
Mar 25 13:45:50 DEBUG[17282] cdr_addon_mysql.c: cdr_mysql: inserting a 
CDR record.
Mar 25 13:45:50 DEBUG[17282] cdr_addon_mysql.c: cdr_mysql: SQL command 
as follows: INSERT INTO cdr 
(calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid)
VALUES ('2006-03-25
13:45:21','','','s','from-pstn',
'Zap/1-1','SIP/3000-dbc4','Dial','SIP/3000|40|r',29,29,'ANSWERED',3,'','1143287116.0')
Mar 25 13:45:50 DEBUG[17282] chan_zap.c: Hangup: channel: 1 index = 0, 
normal = 10, callwait = -1, thirdcall = -1
Mar 25 13:45:50 DEBUG[17282] chan_zap.c: disabled echo cancellation on 
channel 1
Mar 25 13:45:50 DEBUG[17282] chan_zap.c: Set option TDD MODE, value: 
OFF(0) on Zap/1-1
Mar 25 13:45:50 DEBUG[17282] chan_zap.c: Updated conferencing on 1, with 
0 conference users
Mar 25 13:45:50 VERBOSE[17282] logger.c:     -- Hungup 'Zap/1-1'
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------


If I change extensions.conf to read as follows :

exten => s,1,Answer
exten => s,2,AbsoluteTimeout(35)
exten => s,3,Set(FAXFILE=/var/spool/asterisk-fax/${UNIQUEID}.tif)
exten => s,4,rxfax(${FAXFILE}|debug)
exten => T,1,Hangup()

The call gets answered, but I get the following in the log :

Mar 25 13:53:42 DEBUG[17449] dsp.c: dsp busy pattern set to 500,500
Mar 25 13:53:42 VERBOSE[17501] logger.c:     -- Starting simple switch 
on 'Zap/1-1'
Mar 25 13:53:43 NOTICE[17501] chan_zap.c: Got event 18 (Ring Begin)...
Mar 25 13:53:44 NOTICE[17501] chan_zap.c: Got event 2 (Ring/Answered)...
Mar 25 13:53:44 NOTICE[17501] chan_zap.c: Got event 18 (Ring Begin)...
Mar 25 13:53:45 NOTICE[17501] chan_zap.c: Got event 2 (Ring/Answered)...
Mar 25 13:53:46 NOTICE[17501] chan_zap.c: Got event 18 (Ring Begin)...
Mar 25 13:53:46 VERBOSE[17501] logger.c:     -- Executing 
Answer("Zap/1-1", "") in new stack
Mar 25 13:53:46 DEBUG[17501] chan_zap.c: Took Zap/1-1 off hook
Mar 25 13:53:46 DEBUG[17501] chan_zap.c: Enabled echo cancellation on 
channel 1
Mar 25 13:53:46 DEBUG[17501] chan_zap.c: Engaged echo training on channel 1
Mar 25 13:53:46 VERBOSE[17501] logger.c:     -- Executing 
AbsoluteTimeout("Zap/1-1", "35") in new stack
Mar 25 13:53:46 WARNING[17501] pbx.c: AbsoluteTimeout is deprecated, 
please use Set(TIMEOUT(absolute)=timeout) instead.
Mar 25 13:53:46 VERBOSE[17501] logger.c:     -- Set Absolute Timeout to 35
Mar 25 13:53:46 VERBOSE[17501] logger.c:     -- Executing
Set("Zap/1-1",
"FAXFILE=/var/spool/asterisk-fax/1143287622.0.tif") in new stack
Mar 25 13:53:46 VERBOSE[17501] logger.c:     -- Executing 
RxFAX("Zap/1-1",
"/var/spool/asterisk-fax/1143287622.0.tif|debug") in
new stack
Mar 25 13:53:46 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier up
Mar 25 13:53:46 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier down
Mar 25 13:53:47 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier up
Mar 25 13:53:47 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier down
Mar 25 13:53:47 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier up
Mar 25 13:53:47 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier down
Mar 25 13:53:47 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier up
Mar 25 13:53:47 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier down
Mar 25 13:53:47 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier up
Mar 25 13:53:47 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier down
Mar 25 13:53:47 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier up
Mar 25 13:53:47 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier down
Mar 25 13:53:47 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier up
Mar 25 13:53:47 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier down
Mar 25 13:53:48 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier up
Mar 25 13:53:48 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier down
Mar 25 13:53:48 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier up
Mar 25 13:53:48 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier down
Mar 25 13:53:48 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier up
Mar 25 13:53:48 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier down
Mar 25 13:53:49 DEBUG[17501] app_rxfax.c: FLOW Changed from phase 1 to 4
Mar 25 13:53:49 DEBUG[17501] app_rxfax.c: FLOW >>> DIS:Mar 25 13:53:49 
DEBUG[17501] app_rxfax.c:  80Mar 25 13:53:49 DEBUG[17501] app_rxfax.c:  
00Mar 25 13:53:49 DEBUG[17501] app_rxfax.c:  ceMar 25 13:53:49 
DEBUG[17501] app_rxfax.c:  f4Mar 25 13:53:49 DEBUG[17501] app_rxfax.c:  
80Mar 25 13:53:49 DEBUG[17501] app_rxfax.c:  80Mar 25 13:53:49 
DEBUG[17501] app_rxfax.c:  81Mar 25 13:53:49 DEBUG[17501] app_rxfax.c:  
80Mar 25 13:53:49 DEBUG[17501] app_rxfax.c:  80Mar 25 13:53:49 
DEBUG[17501] app_rxfax.c:  80Mar 25 13:53:49 DEBUG[17501] app_rxfax.c:  
18Mar 25 13:53:49 DEBUG[17501] app_rxfax.c:
Mar 25 13:53:51 DEBUG[17501] app_rxfax.c: FLOW HDLC underflow in state 9
Mar 25 13:53:51 DEBUG[17501] app_rxfax.c: FLOW Changed from phase 4 to 3
Mar 25 13:53:51 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier up
Mar 25 13:53:51 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier down
Mar 25 13:53:51 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier up
Mar 25 13:53:51 DEBUG[17501] app_rxfax.c: FLOW HDLC framing OK
Mar 25 13:53:53 DEBUG[17501] app_rxfax.c: FLOW <<< TSI:Mar 25 13:53:53 
DEBUG[17501] app_rxfax.c:  43Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:  
39Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:  32Mar 25 13:53:53 
DEBUG[17501] app_rxfax.c:  32Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:  
32Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:  36Mar 25 13:53:53 
DEBUG[17501] app_rxfax.c:  32Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:  
34Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:  2bMar 25 13:53:53 
DEBUG[17501] app_rxfax.c:  31Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:  
32Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:  30Mar 25 13:53:53 
DEBUG[17501] app_rxfax.c:  20Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:  
20Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:  20Mar 25 13:53:53 
DEBUG[17501] app_rxfax.c:  20Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:  
20Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:  20Mar 25 13:53:53 
DEBUG[17501] app_rxfax.c:  20Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:  
20Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:  20Mar 25 13:53:53 
DEBUG[17501] app_rxfax.c:
Mar 25 13:53:53 DEBUG[17501] app_rxfax.c: FLOW TSI without final frame tag
Mar 25 13:53:53 DEBUG[17501] app_rxfax.c: FLOW Remote fax gave TSI as: 
"021+4262229"
Mar 25 13:53:53 DEBUG[17501] app_rxfax.c: FLOW <<< DCS:Mar 25 13:53:53 
DEBUG[17501] app_rxfax.c:  83Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:  
00Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:  86Mar 25 13:53:53 
DEBUG[17501] app_rxfax.c:  a4Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:  
00Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:
Mar 25 13:53:53 DEBUG[17501] app_rxfax.c: FLOW DCS with final frame tag
Mar 25 13:53:53 DEBUG[17501] app_rxfax.c: FLOW In state 9
Mar 25 13:53:53 DEBUG[17501] app_rxfax.c: FLOW Get at 9600bps, modem 1
Mar 25 13:53:53 DEBUG[17501] app_rxfax.c: FLOW Changed from phase 3 to 5
Mar 25 13:53:53 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier up
Mar 25 13:53:53 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier training 
failed
Mar 25 13:53:55 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier down
Mar 25 13:53:58 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier up
Mar 25 13:53:58 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier training 
failed
Mar 25 13:54:00 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier down
Mar 25 13:54:00 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier up
Mar 25 13:54:00 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier training 
failed
Mar 25 13:54:02 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier down
Mar 25 13:54:04 DEBUG[17450] chan_sip.c: Stopping retransmission on 
'76a78ede698fa5e658232143526319d9@192.168.1.76' of Request 102: Match
Found
Mar 25 13:54:05 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier up
Mar 25 13:54:05 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier training 
failed
Mar 25 13:54:07 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier down
Mar 25 13:54:07 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier up
Mar 25 13:54:07 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier training 
failed
Mar 25 13:54:09 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier down
Mar 25 13:54:12 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier up
Mar 25 13:54:12 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier training 
failed
Mar 25 13:54:13 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier down
Mar 25 13:54:13 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier up
Mar 25 13:54:13 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier down
Mar 25 13:54:14 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier up
Mar 25 13:54:14 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier training 
failed
Mar 25 13:54:14 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier down
Mar 25 13:54:15 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier up
Mar 25 13:54:15 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier training 
failed
Mar 25 13:54:15 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier down
Mar 25 13:54:16 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier up
Mar 25 13:54:16 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier training 
failed
Mar 25 13:54:16 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier down
Mar 25 13:54:17 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier up
Mar 25 13:54:17 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier training 
failed
Mar 25 13:54:17 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier down
Mar 25 13:54:18 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier up
Mar 25 13:54:18 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier training 
failed
Mar 25 13:54:18 DEBUG[17501] dsp.c: ast_dsp_busydetect detected busy, 
avgtone: 500, avgsilence 500
Mar 25 13:54:18 DEBUG[17501] dsp.c: Requesting Hangup because the busy 
tone was detected on channel Zap/1-1
Mar 25 13:54:18 DEBUG[17501] app_rxfax.c: Got hangup
Mar 25 13:54:18 DEBUG[17501] pbx.c: Extension s, priority 4 returned 
normally even though call was hung up
Mar 25 13:54:18 DEBUG[17501] cdr_addon_mysql.c: cdr_mysql: inserting a 
CDR record.
Mar 25 13:54:18 DEBUG[17501] cdr_addon_mysql.c: cdr_mysql: SQL command 
as follows: INSERT INTO cdr 
(calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid)
VALUES ('2006-03-25
13:53:46','','','s','from-pstn',
'Zap/1-1','','RxFAX','/var/spool/asterisk-fax/1143287622.0.tif|debug',32,32,'ANSWERED',3,'','1143287622.0')
Mar 25 13:54:18 DEBUG[17501] chan_zap.c: Hangup: channel: 1 index = 0, 
normal = 10, callwait = -1, thirdcall = -1
Mar 25 13:54:18 DEBUG[17501] chan_zap.c: disabled echo cancellation on 
channel 1
Mar 25 13:54:18 DEBUG[17501] chan_zap.c: Set option TDD MODE, value: 
OFF(0) on Zap/1-1
Mar 25 13:54:18 DEBUG[17501] chan_zap.c: Updated conferencing on 1, with 
0 conference users
Mar 25 13:54:18 VERBOSE[17501] logger.c:     -- Hungup 'Zap/1-1'

I have received a fax from a different machine with this config, but I 
would like to be able to have the faxes pulled out from incoming calls 
and voice going to a digital receptionist .

Thanx
Thys de Wet
Cape Town
South Africa

picciuX

2006-Mar-26 04:04 UTC

head link

[Asterisk-Users] Asterisk spanDSP / Faxing problem

You should put something between answer and dial, to let * have time to get
the fax tone: with your dialplan, the call is immediatly bridged to
SIP/3000, so no fax detection happen at all.
A thing like:

exten => s,1,Answer
exten => s,2,Playtones(ring)
exten => s,3,Wait(3) ; if fax tone comes here, * should jump to fax
extension
exten => s,4,StopPlaytones
exten => s,5,Dial(SIP/300....

exten => fax,1,......
.....

Hote This helps



2006/3/25, Thys de Wet <thys@playlogix.com>:>
> Hi There.
> I have the following setup :
> Asterisk 1.2.4 , freePBX 2.0.1, spandsp-0.0.2pre24
>
> My problem is as follows :
> If I set up a very simple extensions.conf. when I dial from a fax
> machine, it seems as if no fax is being recognised.
> If I answer the call, I can hear the fax machine beeping.
>
>
>
> extensions.conf :
>
>
-----------------------------------------------------------------------------------------------------------
> [from-pstn]
> ; Answer the line and listen
> exten => s,1,Answer
> ; Dial an extension, let asterisk give a ringtone
> exten => s,2,Dial(SIP/3000,40,r)
> ; Hangup if nobody picked up within 40 seconds
> exten => s,3,Hangup
>
> ; Did we get a fax?   <--------------------------Seems as if we never
> get this far :(((((
> exten => fax,1,SetVar(FAXFILE=/var/spool/asterisk-fax/${UNIQUEID}.tif)
> exten => fax,2,rxfax(${FAXFILE}|debug)
>
>
-------------------------------------------------------------------------------------------------------------
> zapata.conf :
>
>
-------------------------------------------------------------------------------------------------------------
> [trunkgroups]
> ; define any trunk groups
> [channels]
> ; hardware channels
> ; default
> usecallerid=yes
> hidecallerid=no
> callwaiting=no
> threewaycalling=yes
> transfer=yes
> echocancel=yes
> echotraining=yes
>
> faxdetect=both
> busydetect=yes
> busycount=4
> busypattern=500,500
> callprogress=no
>
>
> ; define channels
> context=from-pstn ;
> signalling=fxs_ls ;
> channel=>1-3 ;
>
> context=aa_1 ;
> signalling=fxs_ls ;
> channel=>4 ;
>
>
--------------------------------------------------------------------------------------------------------------------------------------------------
> Output from asterisk log :
>
> Mar 25 13:45:16 VERBOSE[17282] logger.c:     -- Starting simple switch
> on 'Zap/1-1'
> Mar 25 13:45:18 NOTICE[17282] chan_zap.c: Got event 18 (Ring Begin)...
> Mar 25 13:45:19 NOTICE[17282] chan_zap.c: Got event 2 (Ring/Answered)...
> Mar 25 13:45:21 NOTICE[17282] chan_zap.c: Got event 18 (Ring Begin)...
> Mar 25 13:45:21 VERBOSE[17282] logger.c:     -- Executing
> Answer("Zap/1-1", "") in new stack
> Mar 25 13:45:21 DEBUG[17282] chan_zap.c: Took Zap/1-1 off hook
> Mar 25 13:45:21 DEBUG[17282] chan_zap.c: Enabled echo cancellation on
> channel 1
> Mar 25 13:45:21 DEBUG[17282] chan_zap.c: Engaged echo training on channel
> 1
> Mar 25 13:45:21 VERBOSE[17282] logger.c:     -- Executing
> Dial("Zap/1-1", "SIP/3000|40|r") in new stack
> Mar 25 13:45:21 DEBUG[17282] chan_sip.c: Setting NAT on RTP to 0
> Mar 25 13:45:21 DEBUG[17282] chan_sip.c: Outgoing Call for 3000
> Mar 25 13:45:21 VERBOSE[17282] logger.c:     -- Called 3000
> Mar 25 13:45:21 DEBUG[17282] chan_zap.c: Requested indication 3 on
> channel Zap/1-1
> Mar 25 13:45:21 DEBUG[17229] chan_sip.c: (Provisional) Stopping
> retransmission (but retaining packet) on
> '5f8bf93a4e7e14fa4b9c2319609192c6@192.168.1.76' Request 102: Found
> Mar 25 13:45:21 DEBUG[17229] chan_sip.c: (Provisional) Stopping
> retransmission (but retaining packet) on
> '5f8bf93a4e7e14fa4b9c2319609192c6@192.168.1.76' Request 102: Found
> Mar 25 13:45:21 VERBOSE[17282] logger.c:     -- SIP/3000-dbc4 is ringing
> Mar 25 13:45:21 DEBUG[17222] channel.c: Avoiding initial deadlock for
> 'SIP/3000-dbc4'
> Mar 25 13:45:29 DEBUG[17229] chan_sip.c: Acked pending invite 102
> Mar 25 13:45:29 DEBUG[17229] chan_sip.c: Stopping retransmission on
> '5f8bf93a4e7e14fa4b9c2319609192c6@192.168.1.76' of Request 102:
Match
> Found
> Mar 25 13:45:29 DEBUG[17229] chan_sip.c: build_route: Contact hop:
> <sip:3000@192.168.1.74>
> Mar 25 13:45:29 VERBOSE[17282] logger.c:     -- SIP/3000-dbc4 answered
> Zap/1-1
> Mar 25 13:45:29 DEBUG[17282] chan_zap.c: Requested indication -1 on
> channel Zap/1-1
> Mar 25 13:45:50 DEBUG[17282] channel.c: Didn't get a frame from
channel:
> SIP/3000-dbc4
> Mar 25 13:45:50 DEBUG[17282] channel.c: Bridge stops bridging channels
> Zap/1-1 and SIP/3000-dbc4
> Mar 25 13:45:50 DEBUG[17282] chan_sip.c: update_call_counter(3000) -
> decrement call limit counter
> Mar 25 13:45:50 DEBUG[17282] app_dial.c: Exiting with DIALSTATUS=ANSWER.
> Mar 25 13:45:50 VERBOSE[17282] logger.c:   == Spawn extension
> (from-pstn, s, 2) exited non-zero on 'Zap/1-1'
> Mar 25 13:45:50 DEBUG[17282] cdr_addon_mysql.c: cdr_mysql: inserting a
> CDR record.
> Mar 25 13:45:50 DEBUG[17282] cdr_addon_mysql.c: cdr_mysql: SQL command
> as follows: INSERT INTO cdr
>
>
(calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid)
> VALUES ('2006-03-25
13:45:21','','','s','from-pstn',
>
'Zap/1-1','SIP/3000-dbc4','Dial','SIP/3000|40|r',29,29,'ANSWERED',3,'','
> 1143287116.0')
> Mar 25 13:45:50 DEBUG[17282] chan_zap.c: Hangup: channel: 1 index = 0,
> normal = 10, callwait = -1, thirdcall = -1
> Mar 25 13:45:50 DEBUG[17282] chan_zap.c: disabled echo cancellation on
> channel 1
> Mar 25 13:45:50 DEBUG[17282] chan_zap.c: Set option TDD MODE, value:
> OFF(0) on Zap/1-1
> Mar 25 13:45:50 DEBUG[17282] chan_zap.c: Updated conferencing on 1, with
> 0 conference users
> Mar 25 13:45:50 VERBOSE[17282] logger.c:     -- Hungup 'Zap/1-1'
>
>
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------
>
>
> If I change extensions.conf to read as follows :
>
> exten => s,1,Answer
> exten => s,2,AbsoluteTimeout(35)
> exten => s,3,Set(FAXFILE=/var/spool/asterisk-fax/${UNIQUEID}.tif)
> exten => s,4,rxfax(${FAXFILE}|debug)
> exten => T,1,Hangup()
>
> The call gets answered, but I get the following in the log :
>
> Mar 25 13:53:42 DEBUG[17449] dsp.c: dsp busy pattern set to 500,500
> Mar 25 13:53:42 VERBOSE[17501] logger.c:     -- Starting simple switch
> on 'Zap/1-1'
> Mar 25 13:53:43 NOTICE[17501] chan_zap.c: Got event 18 (Ring Begin)...
> Mar 25 13:53:44 NOTICE[17501] chan_zap.c: Got event 2 (Ring/Answered)...
> Mar 25 13:53:44 NOTICE[17501] chan_zap.c: Got event 18 (Ring Begin)...
> Mar 25 13:53:45 NOTICE[17501] chan_zap.c: Got event 2 (Ring/Answered)...
> Mar 25 13:53:46 NOTICE[17501] chan_zap.c: Got event 18 (Ring Begin)...
> Mar 25 13:53:46 VERBOSE[17501] logger.c:     -- Executing
> Answer("Zap/1-1", "") in new stack
> Mar 25 13:53:46 DEBUG[17501] chan_zap.c: Took Zap/1-1 off hook
> Mar 25 13:53:46 DEBUG[17501] chan_zap.c: Enabled echo cancellation on
> channel 1
> Mar 25 13:53:46 DEBUG[17501] chan_zap.c: Engaged echo training on channel
> 1
> Mar 25 13:53:46 VERBOSE[17501] logger.c:     -- Executing
> AbsoluteTimeout("Zap/1-1", "35") in new stack
> Mar 25 13:53:46 WARNING[17501] pbx.c: AbsoluteTimeout is deprecated,
> please use Set(TIMEOUT(absolute)=timeout) instead.
> Mar 25 13:53:46 VERBOSE[17501] logger.c:     -- Set Absolute Timeout to 35
> Mar 25 13:53:46 VERBOSE[17501] logger.c:     -- Executing
Set("Zap/1-1",
> "FAXFILE=/var/spool/asterisk-fax/1143287622.0.tif") in new stack
> Mar 25 13:53:46 VERBOSE[17501] logger.c:     -- Executing
> RxFAX("Zap/1-1",
"/var/spool/asterisk-fax/1143287622.0.tif|debug") in
> new stack
> Mar 25 13:53:46 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier up
> Mar 25 13:53:46 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier down
> Mar 25 13:53:47 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier up
> Mar 25 13:53:47 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier down
> Mar 25 13:53:47 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier up
> Mar 25 13:53:47 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier down
> Mar 25 13:53:47 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier up
> Mar 25 13:53:47 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier down
> Mar 25 13:53:47 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier up
> Mar 25 13:53:47 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier down
> Mar 25 13:53:47 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier up
> Mar 25 13:53:47 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier down
> Mar 25 13:53:47 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier up
> Mar 25 13:53:47 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier down
> Mar 25 13:53:48 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier up
> Mar 25 13:53:48 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier down
> Mar 25 13:53:48 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier up
> Mar 25 13:53:48 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier down
> Mar 25 13:53:48 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier up
> Mar 25 13:53:48 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier down
> Mar 25 13:53:49 DEBUG[17501] app_rxfax.c: FLOW Changed from phase 1 to 4
> Mar 25 13:53:49 DEBUG[17501] app_rxfax.c: FLOW >>> DIS:Mar 25
13:53:49
> DEBUG[17501] app_rxfax.c:  80Mar 25 13:53:49 DEBUG[17501] app_rxfax.c:
> 00Mar 25 13:53:49 DEBUG[17501] app_rxfax.c:  ceMar 25 13:53:49
> DEBUG[17501] app_rxfax.c:  f4Mar 25 13:53:49 DEBUG[17501] app_rxfax.c:
> 80Mar 25 13:53:49 DEBUG[17501] app_rxfax.c:  80Mar 25 13:53:49
> DEBUG[17501] app_rxfax.c:  81Mar 25 13:53:49 DEBUG[17501] app_rxfax.c:
> 80Mar 25 13:53:49 DEBUG[17501] app_rxfax.c:  80Mar 25 13:53:49
> DEBUG[17501] app_rxfax.c:  80Mar 25 13:53:49 DEBUG[17501] app_rxfax.c:
> 18Mar 25 13:53:49 DEBUG[17501] app_rxfax.c:
> Mar 25 13:53:51 DEBUG[17501] app_rxfax.c: FLOW HDLC underflow in state 9
> Mar 25 13:53:51 DEBUG[17501] app_rxfax.c: FLOW Changed from phase 4 to 3
> Mar 25 13:53:51 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier up
> Mar 25 13:53:51 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier down
> Mar 25 13:53:51 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier up
> Mar 25 13:53:51 DEBUG[17501] app_rxfax.c: FLOW HDLC framing OK
> Mar 25 13:53:53 DEBUG[17501] app_rxfax.c: FLOW <<< TSI:Mar 25
13:53:53
> DEBUG[17501] app_rxfax.c:  43Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:
> 39Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:  32Mar 25 13:53:53
> DEBUG[17501] app_rxfax.c:  32Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:
> 32Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:  36Mar 25 13:53:53
> DEBUG[17501] app_rxfax.c:  32Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:
> 34Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:  2bMar 25 13:53:53
> DEBUG[17501] app_rxfax.c:  31Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:
> 32Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:  30Mar 25 13:53:53
> DEBUG[17501] app_rxfax.c:  20Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:
> 20Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:  20Mar 25 13:53:53
> DEBUG[17501] app_rxfax.c:  20Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:
> 20Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:  20Mar 25 13:53:53
> DEBUG[17501] app_rxfax.c:  20Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:
> 20Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:  20Mar 25 13:53:53
> DEBUG[17501] app_rxfax.c:
> Mar 25 13:53:53 DEBUG[17501] app_rxfax.c: FLOW TSI without final frame tag
> Mar 25 13:53:53 DEBUG[17501] app_rxfax.c: FLOW Remote fax gave TSI as:
> "021+4262229"
> Mar 25 13:53:53 DEBUG[17501] app_rxfax.c: FLOW <<< DCS:Mar 25
13:53:53
> DEBUG[17501] app_rxfax.c:  83Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:
> 00Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:  86Mar 25 13:53:53
> DEBUG[17501] app_rxfax.c:  a4Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:
> 00Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:
> Mar 25 13:53:53 DEBUG[17501] app_rxfax.c: FLOW DCS with final frame tag
> Mar 25 13:53:53 DEBUG[17501] app_rxfax.c: FLOW In state 9
> Mar 25 13:53:53 DEBUG[17501] app_rxfax.c: FLOW Get at 9600bps, modem 1
> Mar 25 13:53:53 DEBUG[17501] app_rxfax.c: FLOW Changed from phase 3 to 5
> Mar 25 13:53:53 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier up
> Mar 25 13:53:53 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier training
> failed
> Mar 25 13:53:55 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier down
> Mar 25 13:53:58 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier up
> Mar 25 13:53:58 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier training
> failed
> Mar 25 13:54:00 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier down
> Mar 25 13:54:00 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier up
> Mar 25 13:54:00 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier training
> failed
> Mar 25 13:54:02 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier down
> Mar 25 13:54:04 DEBUG[17450] chan_sip.c: Stopping retransmission on
> '76a78ede698fa5e658232143526319d9@192.168.1.76' of Request 102:
Match
> Found
> Mar 25 13:54:05 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier up
> Mar 25 13:54:05 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier training
> failed
> Mar 25 13:54:07 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier down
> Mar 25 13:54:07 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier up
> Mar 25 13:54:07 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier training
> failed
> Mar 25 13:54:09 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier down
> Mar 25 13:54:12 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier up
> Mar 25 13:54:12 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier training
> failed
> Mar 25 13:54:13 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier down
> Mar 25 13:54:13 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier up
> Mar 25 13:54:13 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier down
> Mar 25 13:54:14 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier up
> Mar 25 13:54:14 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier training
> failed
> Mar 25 13:54:14 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier down
> Mar 25 13:54:15 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier up
> Mar 25 13:54:15 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier training
> failed
> Mar 25 13:54:15 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier down
> Mar 25 13:54:16 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier up
> Mar 25 13:54:16 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier training
> failed
> Mar 25 13:54:16 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier down
> Mar 25 13:54:17 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier up
> Mar 25 13:54:17 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier training
> failed
> Mar 25 13:54:17 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier down
> Mar 25 13:54:18 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier up
> Mar 25 13:54:18 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier training
> failed
> Mar 25 13:54:18 DEBUG[17501] dsp.c: ast_dsp_busydetect detected busy,
> avgtone: 500, avgsilence 500
> Mar 25 13:54:18 DEBUG[17501] dsp.c: Requesting Hangup because the busy
> tone was detected on channel Zap/1-1
> Mar 25 13:54:18 DEBUG[17501] app_rxfax.c: Got hangup
> Mar 25 13:54:18 DEBUG[17501] pbx.c: Extension s, priority 4 returned
> normally even though call was hung up
> Mar 25 13:54:18 DEBUG[17501] cdr_addon_mysql.c: cdr_mysql: inserting a
> CDR record.
> Mar 25 13:54:18 DEBUG[17501] cdr_addon_mysql.c: cdr_mysql: SQL command
> as follows: INSERT INTO cdr
>
>
(calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid)
> VALUES ('2006-03-25
13:53:46','','','s','from-pstn',
>
>
'Zap/1-1','','RxFAX','/var/spool/asterisk-fax/1143287622.0.tif|debug',32,32,'ANSWERED',3,'','
> 1143287622.0')
> Mar 25 13:54:18 DEBUG[17501] chan_zap.c: Hangup: channel: 1 index = 0,
> normal = 10, callwait = -1, thirdcall = -1
> Mar 25 13:54:18 DEBUG[17501] chan_zap.c: disabled echo cancellation on
> channel 1
> Mar 25 13:54:18 DEBUG[17501] chan_zap.c: Set option TDD MODE, value:
> OFF(0) on Zap/1-1
> Mar 25 13:54:18 DEBUG[17501] chan_zap.c: Updated conferencing on 1, with
> 0 conference users
> Mar 25 13:54:18 VERBOSE[17501] logger.c:     -- Hungup 'Zap/1-1'
>
> I have received a fax from a different machine with this config, but I
> would like to be able to have the faxes pulled out from incoming calls
> and voice going to a digital receptionist .
>
> Thanx
> Thys de Wet
> Cape Town
> South Africa
>
>
>
> _______________________________________________
> --Bandwidth and Colocation provided by Easynews.com --
>
> Asterisk-Users mailing list
> To UNSUBSCRIBE or update options visit:
>    http://lists.digium.com/mailman/listinfo/asterisk-users
>-------------- next part --------------
An HTML attachment was scrubbed...
URL:
http://lists.digium.com/pipermail/asterisk-users/attachments/20060326/ec860164/attachment.htm

Juan Jose Comellas

2006-Mar-26 06:20 UTC

head link

[Asterisk-Users] Asterisk spanDSP / Faxing problem

For us it takes about 6 seconds to detect fax tones, so you should change your 
dialplan to either play and audio while detecting fax tones 
(NVBackgroundDetect) or Wait for at least 6-7 seconds if using a Zaptel 
channel.

On Sat March 25 2006 08:56, Thys de Wet wrote:> Hi There.
> I have the following setup :
> Asterisk 1.2.4 , freePBX 2.0.1, spandsp-0.0.2pre24
>
> My problem is as follows :
> If I set up a very simple extensions.conf. when I dial from a fax
> machine, it seems as if no fax is being recognised.
> If I answer the call, I can hear the fax machine beeping.
>
>
>
> extensions.conf :
> ---------------------------------------------------------------------------
>-------------------------------- [from-pstn]
>  ; Answer the line and listen
>  exten => s,1,Answer
>  ; Dial an extension, let asterisk give a ringtone
>  exten => s,2,Dial(SIP/3000,40,r)
>  ; Hangup if nobody picked up within 40 seconds
>  exten => s,3,Hangup
>
>  ; Did we get a fax?   <--------------------------Seems as if we never
> get this far :(((((
>  exten => fax,1,SetVar(FAXFILE=/var/spool/asterisk-fax/${UNIQUEID}.tif)
>  exten => fax,2,rxfax(${FAXFILE}|debug)
> ---------------------------------------------------------------------------
>---------------------------------- zapata.conf :
> ---------------------------------------------------------------------------
>---------------------------------- [trunkgroups]
> ; define any trunk groups
> [channels]
> ; hardware channels
> ; default
> usecallerid=yes
> hidecallerid=no
> callwaiting=no
> threewaycalling=yes
> transfer=yes
> echocancel=yes
> echotraining=yes
>
> faxdetect=both
> busydetect=yes
> busycount=4
> busypattern=500,500
> callprogress=no
>
>
> ; define channels
> context=from-pstn ;
> signalling=fxs_ls ;
> channel=>1-3 ;
>
> context=aa_1 ;
> signalling=fxs_ls ;
> channel=>4 ;
> ---------------------------------------------------------------------------
>-----------------------------------------------------------------------
> Output from asterisk log :
>
> Mar 25 13:45:16 VERBOSE[17282] logger.c:     -- Starting simple switch
> on 'Zap/1-1'
> Mar 25 13:45:18 NOTICE[17282] chan_zap.c: Got event 18 (Ring Begin)...
> Mar 25 13:45:19 NOTICE[17282] chan_zap.c: Got event 2 (Ring/Answered)...
> Mar 25 13:45:21 NOTICE[17282] chan_zap.c: Got event 18 (Ring Begin)...
> Mar 25 13:45:21 VERBOSE[17282] logger.c:     -- Executing
> Answer("Zap/1-1", "") in new stack
> Mar 25 13:45:21 DEBUG[17282] chan_zap.c: Took Zap/1-1 off hook
> Mar 25 13:45:21 DEBUG[17282] chan_zap.c: Enabled echo cancellation on
> channel 1
> Mar 25 13:45:21 DEBUG[17282] chan_zap.c: Engaged echo training on channel 1
> Mar 25 13:45:21 VERBOSE[17282] logger.c:     -- Executing
> Dial("Zap/1-1", "SIP/3000|40|r") in new stack
> Mar 25 13:45:21 DEBUG[17282] chan_sip.c: Setting NAT on RTP to 0
> Mar 25 13:45:21 DEBUG[17282] chan_sip.c: Outgoing Call for 3000
> Mar 25 13:45:21 VERBOSE[17282] logger.c:     -- Called 3000
> Mar 25 13:45:21 DEBUG[17282] chan_zap.c: Requested indication 3 on
> channel Zap/1-1
> Mar 25 13:45:21 DEBUG[17229] chan_sip.c: (Provisional) Stopping
> retransmission (but retaining packet) on
> '5f8bf93a4e7e14fa4b9c2319609192c6@192.168.1.76' Request 102: Found
> Mar 25 13:45:21 DEBUG[17229] chan_sip.c: (Provisional) Stopping
> retransmission (but retaining packet) on
> '5f8bf93a4e7e14fa4b9c2319609192c6@192.168.1.76' Request 102: Found
> Mar 25 13:45:21 VERBOSE[17282] logger.c:     -- SIP/3000-dbc4 is ringing
> Mar 25 13:45:21 DEBUG[17222] channel.c: Avoiding initial deadlock for
> 'SIP/3000-dbc4'
> Mar 25 13:45:29 DEBUG[17229] chan_sip.c: Acked pending invite 102
> Mar 25 13:45:29 DEBUG[17229] chan_sip.c: Stopping retransmission on
> '5f8bf93a4e7e14fa4b9c2319609192c6@192.168.1.76' of Request 102:
Match Found
> Mar 25 13:45:29 DEBUG[17229] chan_sip.c: build_route: Contact hop:
> <sip:3000@192.168.1.74>
> Mar 25 13:45:29 VERBOSE[17282] logger.c:     -- SIP/3000-dbc4 answered
> Zap/1-1
> Mar 25 13:45:29 DEBUG[17282] chan_zap.c: Requested indication -1 on
> channel Zap/1-1
> Mar 25 13:45:50 DEBUG[17282] channel.c: Didn't get a frame from
channel:
> SIP/3000-dbc4
> Mar 25 13:45:50 DEBUG[17282] channel.c: Bridge stops bridging channels
> Zap/1-1 and SIP/3000-dbc4
> Mar 25 13:45:50 DEBUG[17282] chan_sip.c: update_call_counter(3000) -
> decrement call limit counter
> Mar 25 13:45:50 DEBUG[17282] app_dial.c: Exiting with DIALSTATUS=ANSWER.
> Mar 25 13:45:50 VERBOSE[17282] logger.c:   == Spawn extension
> (from-pstn, s, 2) exited non-zero on 'Zap/1-1'
> Mar 25 13:45:50 DEBUG[17282] cdr_addon_mysql.c: cdr_mysql: inserting a
> CDR record.
> Mar 25 13:45:50 DEBUG[17282] cdr_addon_mysql.c: cdr_mysql: SQL command
> as follows: INSERT INTO cdr
> (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duratio
>n,billsec,disposition,amaflags,accountcode,uniqueid) VALUES ('2006-03-25
> 13:45:21','','','s','from-pstn',
>
'Zap/1-1','SIP/3000-dbc4','Dial','SIP/3000|40|r',29,29,'ANSWERED',3,'','114
>3287116.0') Mar 25 13:45:50 DEBUG[17282] chan_zap.c: Hangup: channel: 1
> index = 0, normal = 10, callwait = -1, thirdcall = -1
> Mar 25 13:45:50 DEBUG[17282] chan_zap.c: disabled echo cancellation on
> channel 1
> Mar 25 13:45:50 DEBUG[17282] chan_zap.c: Set option TDD MODE, value:
> OFF(0) on Zap/1-1
> Mar 25 13:45:50 DEBUG[17282] chan_zap.c: Updated conferencing on 1, with
> 0 conference users
> Mar 25 13:45:50 VERBOSE[17282] logger.c:     -- Hungup 'Zap/1-1'
> ---------------------------------------------------------------------------
>----------------------------------------------------------------------------
>----------------------
>
>
> If I change extensions.conf to read as follows :
>
> exten => s,1,Answer
> exten => s,2,AbsoluteTimeout(35)
> exten => s,3,Set(FAXFILE=/var/spool/asterisk-fax/${UNIQUEID}.tif)
> exten => s,4,rxfax(${FAXFILE}|debug)
> exten => T,1,Hangup()
>
> The call gets answered, but I get the following in the log :
>
> Mar 25 13:53:42 DEBUG[17449] dsp.c: dsp busy pattern set to 500,500
> Mar 25 13:53:42 VERBOSE[17501] logger.c:     -- Starting simple switch
> on 'Zap/1-1'
> Mar 25 13:53:43 NOTICE[17501] chan_zap.c: Got event 18 (Ring Begin)...
> Mar 25 13:53:44 NOTICE[17501] chan_zap.c: Got event 2 (Ring/Answered)...
> Mar 25 13:53:44 NOTICE[17501] chan_zap.c: Got event 18 (Ring Begin)...
> Mar 25 13:53:45 NOTICE[17501] chan_zap.c: Got event 2 (Ring/Answered)...
> Mar 25 13:53:46 NOTICE[17501] chan_zap.c: Got event 18 (Ring Begin)...
> Mar 25 13:53:46 VERBOSE[17501] logger.c:     -- Executing
> Answer("Zap/1-1", "") in new stack
> Mar 25 13:53:46 DEBUG[17501] chan_zap.c: Took Zap/1-1 off hook
> Mar 25 13:53:46 DEBUG[17501] chan_zap.c: Enabled echo cancellation on
> channel 1
> Mar 25 13:53:46 DEBUG[17501] chan_zap.c: Engaged echo training on channel 1
> Mar 25 13:53:46 VERBOSE[17501] logger.c:     -- Executing
> AbsoluteTimeout("Zap/1-1", "35") in new stack
> Mar 25 13:53:46 WARNING[17501] pbx.c: AbsoluteTimeout is deprecated,
> please use Set(TIMEOUT(absolute)=timeout) instead.
> Mar 25 13:53:46 VERBOSE[17501] logger.c:     -- Set Absolute Timeout to 35
> Mar 25 13:53:46 VERBOSE[17501] logger.c:     -- Executing
Set("Zap/1-1",
> "FAXFILE=/var/spool/asterisk-fax/1143287622.0.tif") in new stack
> Mar 25 13:53:46 VERBOSE[17501] logger.c:     -- Executing
> RxFAX("Zap/1-1",
"/var/spool/asterisk-fax/1143287622.0.tif|debug") in
> new stack
> Mar 25 13:53:46 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier up
> Mar 25 13:53:46 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier down
> Mar 25 13:53:47 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier up
> Mar 25 13:53:47 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier down
> Mar 25 13:53:47 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier up
> Mar 25 13:53:47 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier down
> Mar 25 13:53:47 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier up
> Mar 25 13:53:47 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier down
> Mar 25 13:53:47 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier up
> Mar 25 13:53:47 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier down
> Mar 25 13:53:47 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier up
> Mar 25 13:53:47 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier down
> Mar 25 13:53:47 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier up
> Mar 25 13:53:47 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier down
> Mar 25 13:53:48 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier up
> Mar 25 13:53:48 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier down
> Mar 25 13:53:48 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier up
> Mar 25 13:53:48 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier down
> Mar 25 13:53:48 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier up
> Mar 25 13:53:48 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier down
> Mar 25 13:53:49 DEBUG[17501] app_rxfax.c: FLOW Changed from phase 1 to 4
> Mar 25 13:53:49 DEBUG[17501] app_rxfax.c: FLOW >>> DIS:Mar 25
13:53:49
> DEBUG[17501] app_rxfax.c:  80Mar 25 13:53:49 DEBUG[17501] app_rxfax.c:
> 00Mar 25 13:53:49 DEBUG[17501] app_rxfax.c:  ceMar 25 13:53:49
> DEBUG[17501] app_rxfax.c:  f4Mar 25 13:53:49 DEBUG[17501] app_rxfax.c:
> 80Mar 25 13:53:49 DEBUG[17501] app_rxfax.c:  80Mar 25 13:53:49
> DEBUG[17501] app_rxfax.c:  81Mar 25 13:53:49 DEBUG[17501] app_rxfax.c:
> 80Mar 25 13:53:49 DEBUG[17501] app_rxfax.c:  80Mar 25 13:53:49
> DEBUG[17501] app_rxfax.c:  80Mar 25 13:53:49 DEBUG[17501] app_rxfax.c:
> 18Mar 25 13:53:49 DEBUG[17501] app_rxfax.c:
> Mar 25 13:53:51 DEBUG[17501] app_rxfax.c: FLOW HDLC underflow in state 9
> Mar 25 13:53:51 DEBUG[17501] app_rxfax.c: FLOW Changed from phase 4 to 3
> Mar 25 13:53:51 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier up
> Mar 25 13:53:51 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier down
> Mar 25 13:53:51 DEBUG[17501] app_rxfax.c: FLOW HDLC carrier up
> Mar 25 13:53:51 DEBUG[17501] app_rxfax.c: FLOW HDLC framing OK
> Mar 25 13:53:53 DEBUG[17501] app_rxfax.c: FLOW <<< TSI:Mar 25
13:53:53
> DEBUG[17501] app_rxfax.c:  43Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:
> 39Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:  32Mar 25 13:53:53
> DEBUG[17501] app_rxfax.c:  32Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:
> 32Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:  36Mar 25 13:53:53
> DEBUG[17501] app_rxfax.c:  32Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:
> 34Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:  2bMar 25 13:53:53
> DEBUG[17501] app_rxfax.c:  31Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:
> 32Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:  30Mar 25 13:53:53
> DEBUG[17501] app_rxfax.c:  20Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:
> 20Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:  20Mar 25 13:53:53
> DEBUG[17501] app_rxfax.c:  20Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:
> 20Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:  20Mar 25 13:53:53
> DEBUG[17501] app_rxfax.c:  20Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:
> 20Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:  20Mar 25 13:53:53
> DEBUG[17501] app_rxfax.c:
> Mar 25 13:53:53 DEBUG[17501] app_rxfax.c: FLOW TSI without final frame tag
> Mar 25 13:53:53 DEBUG[17501] app_rxfax.c: FLOW Remote fax gave TSI as:
> "021+4262229"
> Mar 25 13:53:53 DEBUG[17501] app_rxfax.c: FLOW <<< DCS:Mar 25
13:53:53
> DEBUG[17501] app_rxfax.c:  83Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:
> 00Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:  86Mar 25 13:53:53
> DEBUG[17501] app_rxfax.c:  a4Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:
> 00Mar 25 13:53:53 DEBUG[17501] app_rxfax.c:
> Mar 25 13:53:53 DEBUG[17501] app_rxfax.c: FLOW DCS with final frame tag
> Mar 25 13:53:53 DEBUG[17501] app_rxfax.c: FLOW In state 9
> Mar 25 13:53:53 DEBUG[17501] app_rxfax.c: FLOW Get at 9600bps, modem 1
> Mar 25 13:53:53 DEBUG[17501] app_rxfax.c: FLOW Changed from phase 3 to 5
> Mar 25 13:53:53 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier up
> Mar 25 13:53:53 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier training
> failed
> Mar 25 13:53:55 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier down
> Mar 25 13:53:58 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier up
> Mar 25 13:53:58 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier training
> failed
> Mar 25 13:54:00 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier down
> Mar 25 13:54:00 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier up
> Mar 25 13:54:00 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier training
> failed
> Mar 25 13:54:02 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier down
> Mar 25 13:54:04 DEBUG[17450] chan_sip.c: Stopping retransmission on
> '76a78ede698fa5e658232143526319d9@192.168.1.76' of Request 102:
Match Found
> Mar 25 13:54:05 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier up
> Mar 25 13:54:05 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier training
> failed
> Mar 25 13:54:07 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier down
> Mar 25 13:54:07 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier up
> Mar 25 13:54:07 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier training
> failed
> Mar 25 13:54:09 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier down
> Mar 25 13:54:12 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier up
> Mar 25 13:54:12 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier training
> failed
> Mar 25 13:54:13 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier down
> Mar 25 13:54:13 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier up
> Mar 25 13:54:13 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier down
> Mar 25 13:54:14 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier up
> Mar 25 13:54:14 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier training
> failed
> Mar 25 13:54:14 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier down
> Mar 25 13:54:15 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier up
> Mar 25 13:54:15 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier training
> failed
> Mar 25 13:54:15 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier down
> Mar 25 13:54:16 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier up
> Mar 25 13:54:16 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier training
> failed
> Mar 25 13:54:16 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier down
> Mar 25 13:54:17 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier up
> Mar 25 13:54:17 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier training
> failed
> Mar 25 13:54:17 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier down
> Mar 25 13:54:18 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier up
> Mar 25 13:54:18 DEBUG[17501] app_rxfax.c: FLOW Non-ECM carrier training
> failed
> Mar 25 13:54:18 DEBUG[17501] dsp.c: ast_dsp_busydetect detected busy,
> avgtone: 500, avgsilence 500
> Mar 25 13:54:18 DEBUG[17501] dsp.c: Requesting Hangup because the busy
> tone was detected on channel Zap/1-1
> Mar 25 13:54:18 DEBUG[17501] app_rxfax.c: Got hangup
> Mar 25 13:54:18 DEBUG[17501] pbx.c: Extension s, priority 4 returned
> normally even though call was hung up
> Mar 25 13:54:18 DEBUG[17501] cdr_addon_mysql.c: cdr_mysql: inserting a
> CDR record.
> Mar 25 13:54:18 DEBUG[17501] cdr_addon_mysql.c: cdr_mysql: SQL command
> as follows: INSERT INTO cdr
> (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duratio
>n,billsec,disposition,amaflags,accountcode,uniqueid) VALUES ('2006-03-25
> 13:53:46','','','s','from-pstn',
>
'Zap/1-1','','RxFAX','/var/spool/asterisk-fax/1143287622.0.tif|debug',32,32
>,'ANSWERED',3,'','1143287622.0') Mar 25 13:54:18
DEBUG[17501] chan_zap.c:
> Hangup: channel: 1 index = 0, normal = 10, callwait = -1, thirdcall = -1
> Mar 25 13:54:18 DEBUG[17501] chan_zap.c: disabled echo cancellation on
> channel 1
> Mar 25 13:54:18 DEBUG[17501] chan_zap.c: Set option TDD MODE, value:
> OFF(0) on Zap/1-1
> Mar 25 13:54:18 DEBUG[17501] chan_zap.c: Updated conferencing on 1, with
> 0 conference users
> Mar 25 13:54:18 VERBOSE[17501] logger.c:     -- Hungup 'Zap/1-1'
>
> I have received a fax from a different machine with this config, but I
> would like to be able to have the faxes pulled out from incoming calls
> and voice going to a digital receptionist .
>
> Thanx
> Thys de Wet
> Cape Town
> South Africa
>
>
>
> _______________________________________________
> --Bandwidth and Colocation provided by Easynews.com --
>
> Asterisk-Users mailing list
> To UNSUBSCRIBE or update options visit:
>    http://lists.digium.com/mailman/listinfo/asterisk-users
-- 
Juan Jose Comellas
(juanjo@comellas.com.ar)

Apparently Analagous Threads

Search for more reasonably related threads

asterisk users - Mar 2006 - Asterisk spanDSP / Faxing problem

[Asterisk-Users] Asterisk spanDSP / Faxing problem

[Asterisk-Users] Asterisk spanDSP / Faxing problem

[Asterisk-Users] Asterisk spanDSP / Faxing problem

Apparently Analagous Threads