[asterisk-users] Asterisk 1.6.1.13 and T.38 faxing

Tue Feb 2 07:00:47 CST 2010

Hello everyone.

I'm struggling to get T.38 faxing to work in Asterisk 1.6.1.13 with a SIP DID provider here in Brazil (GVT - Vox IP service). Here's my scenario:

When faxes arrive by a specific DID, they are routed thru this simple macro:

[macro-recebefax]

exten => s,1,Set(DB(fax/count)=$[${DB(fax/count)} + 1])
exten => s,n,Set(FAXCOUNT=${DB(fax/count)})
exten => s,n,Set(FAXFILE=fax-${DB(fax/count)}-rx)
exten => s,n,Answer()
exten => s,n,Wait(3)
exten => s,n,ReceiveFAX(/var/spool/asterisk/fax/${FAXFILE}.tif)
exten => s,n,NoOp(FAXSTATUS = ${FAXSTATUS})
exten => s,n,NoOp(FAXERROR = ${FAXERROR})
exten => s,n,NoOp(CALLID = ${CALLERID(name)} ${CALLERID(num)} ${REMOTESTATIONID})
exten => s,n,NoOp(FAXPAGES = ${FAXPAGES})
exten => s,n,NoOp(FAXBITRATE = ${FAXBITRATE})
exten => s,n,NoOp(FAXRESOLUTION = ${FAXRESOLUTION})
exten => s,n,NoOp(FAXMODE = ${FAXMODE})

exten => h,1,System(tiff2pdf -o /var/spool/asterisk/fax/${FAXFILE}.pdf -p A4 /var/spool/asterisk/fax/${FAXFILE}.tif)
exten => h,n,System(rm /var/spool/asterisk/fax/${FAXFILE}.tif)
exten => h,n,System(echo "Fax recebido." > /tmp/${FAXFILE}.txt)
exten => h,n,System(echo "Remetente: ${CALLID}" >> /tmp/${FAXFILE}.txt)
exten => h,n,System(echo "Paginas: ${FAXPAGES}" >> /tmp/${FAXFILE}.txt)
exten => h,n,System(echo "Velocidade de transmissao: ${FAXBITRATE} bps" >> /tmp/${FAXFILE}.txt)
exten => h,n,System(echo "Resolucao: ${FAXRESOLUTION}" >> /tmp/${FAXFILE}.txt)
exten => h,n,System(mutt -s "Allvo FAX" -a /var/spool/asterisk/fax/${FAXFILE}.pdf vinicius at canall.com.br < /tmp/${FAXFILE}.txt)
exten => h,n,System(rm /tmp/${FAXFILE}.txt)

I'm using here app_fax that comes with Asterisk, not the res_fax and res_fax_digium that comes with FFA.

What happens is sometimes the T.38 negotiation goes well and others it fails completely. That's what I got from the debug info on two different calls, without changing any configs:

[Feb  2 08:38:56] DEBUG[21032]: chan_sip.c:7589 process_sdp: Processing session-level SDP v=0... UNSUPPORTED.
[Feb  2 08:38:56] DEBUG[21032]: chan_sip.c:7589 process_sdp: Processing session-level SDP o=PVG 1265107050040 1265107050040 IN IP4 10.152.0.164... UNSUPPORTED.
[Feb  2 08:38:56] DEBUG[21032]: chan_sip.c:7589 process_sdp: Processing session-level SDP s=-... UNSUPPORTED.
[Feb  2 08:38:56] DEBUG[21032]: chan_sip.c:7589 process_sdp: Processing session-level SDP p=+1 6135555555... UNSUPPORTED.
[Feb  2 08:38:56] DEBUG[21032]: chan_sip.c:7589 process_sdp: Processing session-level SDP c=IN IP4 10.152.0.164... OK.
[Feb  2 08:38:56] DEBUG[21032]: chan_sip.c:7589 process_sdp: Processing session-level SDP t=0 0... UNSUPPORTED.
[Feb  2 08:38:56] DEBUG[21032]: chan_sip.c:7753 process_sdp: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK.
[Feb  2 08:38:56] DEBUG[21032]: chan_sip.c:7753 process_sdp: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED.
[Feb  2 08:38:56] DEBUG[21032]: chan_sip.c:7753 process_sdp: Processing media-level (audio) SDP a=ptime:20... OK.
[Feb  2 08:38:56] DEBUG[21032]: chan_sip.c:7753 process_sdp: Processing media-level (audio) SDP a=fmtp:18 annexb=no... UNSUPPORTED.
[Feb  2 08:38:56] DEBUG[21032]: chan_sip.c:8289 process_sdp_a_image: FaxVersion: 0
[Feb  2 08:38:56] DEBUG[21032]: chan_sip.c:7753 process_sdp: Processing media-level (image) SDP a=T38FaxVersion:0... OK.
[Feb  2 08:38:56] DEBUG[21032]: chan_sip.c:8263 process_sdp_a_image: MaxBufferSize:1100
[Feb  2 08:38:56] DEBUG[21032]: chan_sip.c:7753 process_sdp: Processing media-level (image) SDP a=T38FaxMaxBuffer:1100... OK.
[Feb  2 08:38:56] DEBUG[21032]: chan_sip.c:8298 process_sdp_a_image: FaxMaxDatagram: 612
[Feb  2 08:38:56] DEBUG[21032]: chan_sip.c:7753 process_sdp: Processing media-level (image) SDP a=T38FaxMaxDatagram:612... OK.
[Feb  2 08:38:56] DEBUG[21032]: chan_sip.c:8266 process_sdp_a_image: T38MaxBitRate: 14400
[Feb  2 08:38:56] DEBUG[21032]: chan_sip.c:7753 process_sdp: Processing media-level (image) SDP a=T38MaxBitRate:14400... OK.
[Feb  2 08:38:56] DEBUG[21032]: chan_sip.c:8335 process_sdp_a_image: RateManagement: transferredTCF
[Feb  2 08:38:56] DEBUG[21032]: chan_sip.c:7753 process_sdp: Processing media-level (image) SDP a=T38FaxRateManagement:transferredTCF... OK.
[Feb  2 08:38:56] DEBUG[21032]: chan_sip.c:8342 process_sdp_a_image: UDP EC: t38UDPRedundancy

[Feb  2 08:38:06] DEBUG[21032]: chan_sip.c:7589 process_sdp: Processing session-level SDP v=0... UNSUPPORTED.
[Feb  2 08:38:06] DEBUG[21032]: chan_sip.c:7589 process_sdp: Processing session-level SDP o=PVG 1265107000170 1265107000170 IN IP4 10.152.0.164... UNSUPPORTED.
[Feb  2 08:38:06] DEBUG[21032]: chan_sip.c:7589 process_sdp: Processing session-level SDP s=-... UNSUPPORTED.
[Feb  2 08:38:06] DEBUG[21032]: chan_sip.c:7589 process_sdp: Processing session-level SDP p=+1 6135555555... UNSUPPORTED.
[Feb  2 08:38:06] DEBUG[21032]: chan_sip.c:7589 process_sdp: Processing session-level SDP c=IN IP4 10.152.0.164... OK.
[Feb  2 08:38:06] DEBUG[21032]: chan_sip.c:7589 process_sdp: Processing session-level SDP t=0 0... UNSUPPORTED.
[Feb  2 08:38:06] DEBUG[21032]: chan_sip.c:7589 process_sdp: Processing session-level SDP a=sqn: 0... UNSUPPORTED.
[Feb  2 08:38:06] DEBUG[21032]: chan_sip.c:7589 process_sdp: Processing session-level SDP a=cdsc: 1 image udptl t38... UNSUPPORTED.
[Feb  2 08:38:06] DEBUG[21032]: chan_sip.c:7589 process_sdp: Processing session-level SDP a=cpar: a=T38FaxVersion:0... UNSUPPORTED.
[Feb  2 08:38:06] DEBUG[21032]: chan_sip.c:7589 process_sdp: Processing session-level SDP a=cpar: a=T38FaxUdpEC:t38UDPRedundancy... UNSUPPORTED.
[Feb  2 08:38:06] DEBUG[21032]: chan_sip.c:7753 process_sdp: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK.
[Feb  2 08:38:06] DEBUG[21032]: chan_sip.c:7753 process_sdp: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED.
[Feb  2 08:38:06] DEBUG[21032]: chan_sip.c:7753 process_sdp: Processing media-level (audio) SDP a=ptime:20... OK.
[Feb  2 08:38:06] DEBUG[21032]: chan_sip.c:4653 change_t38_state: T38 state changed to 0 on channel SIP/voxip-00000000
[Feb  2 08:38:06] DEBUG[21032]: chan_sip.c:7932 process_sdp: We're settling with these formats: 0x8 (alaw)
[Feb  2 08:38:06] DEBUG[21032]: chan_sip.c:7937 process_sdp: We have an owner, now see if we need to change this call
[Feb  2 08:38:06] DEBUG[21032]: chan_sip.c:5231 update_call_counter: Updating call counter for incoming call
[Feb  2 08:38:06] DEBUG[21032]: chan_sip.c:3172 __sip_xmit: Trying to put 'ACK sip:10.' onto UDP socket destined for 10.150.65.16:5060
[Feb  2 08:38:06] DEBUG[21064]: app_fax.c:699 transmit_t38: Shut down T.38 on SIP/voxip-00000000

Note how items like T38FaxUdpEC are listed as OK on one call and unsupported on another one. Could that be a bug? I can show the entire SIP conversations if that's necessary for debugging this.

Atenciosamente,

Vinícius Fontes
Gerente de Segurança da Informação
Canall Tecnologia em Comunicações
Passo Fundo - RS - Brasil
+55 54 2104-7000

Information Security Manager
Canall Tecnologia em Comunicações
Passo Fundo - RS - Brazil
+55 54 2104-7000