Re: FAX not working throug FAX server

jordisuste · ‎12-15-2010

Hi,

We have a VoIP network working perfectly. We have 12 faxes, with 3 VG204 connected. We now want to add a fax server. Everything is configured but it is not working. The protocol used is T38.

This is the voice gateway (2921) configuration:

voice service voip
allow-connections h323 to h323
allow-connections h323 to sip
allow-connections sip to h323
allow-connections sip to sip
fax protocol t38 ls-redundancy 0 hs-redundancy 0 fallback pass-through g711ulaw
h323
h225 signal overlap
call preserve limit-media-detection
!

!
dial-peer voice 99 voip
description *** FAX Server ***
destination-pattern 192
session protocol sipv2
session target ipv4:192.168.1.254
session transport udp
codec g711ulaw
fax protocol t38 ls-redundancy 0 hs-redundancy 0 fallback pass-through g711ulaw
no vad
!

192.168.1.254 is the fax server IP.

The FAX server is a XCAPI server by T-SYSTEMS. We also have a SIP trunk and a route-pattern to 19[2-3] (the DN of the faxes). We also have directory number 192 and 192 created.

I have attached the "dbud ccsip all" from 2 connections.

Calling FAX: 493039735199

Called FAX: 493586763192

The server is showing two errors:

This one in the log file;

CONNECT_IND
CIP Value               : 1 (Speech)
Called Number           : 192
Calling Number          : 003039735299
Accept Call             : 15-Dec-10 13:05:43
Selected Protocol       : Phone
CONNECT_RESP
CONNECT_ACTIVE_IND
CONNECT_ACTIVE_RESP
CONNECT_B3_IND
CONNECT_B3_RESP
CONNECT_B3_ACTIVE_IND
CONNECT_B3_ACTIVE_RESP
DISCONNECT_B3_REQ
DISCONNECT_B3_CONF
DISCONNECT_B3_IND
DISCONNECT_B3_RESP
Fax Protocol: Initialized (T30 Extended) (Rx Mode)
CONNECT_B3_IND
CONNECT_B3_RESP
CONNECT_B3_ACTIVE_IND
Speed      : 14400
Resolution : Low
ECM        : Used
Pages      : 0
ID         : +493039735299
CONNECT_B3_ACTIVE_RESP
DISCONNECT_B3_IND (0x3312) Fax training error
Speed      : 14400
Resolution : Low
ECM        : Used
Pages      : 0
ID         : +493039735299
DISCONNECT_B3_RESP
DISCONNECT_REQ
DISCONNECT_CONF
DISCONNECT_IND
DISCONNECT_RESP
ISDN_API_RELEASE (ApplID: 1)
ISDN_API_REGISTER (ApplID: 1)
RECEIVE ENABLE: OK

And error 488 (channel not available) in the trace. (in the attached file)

Any ideas? Why could be the reason it is not working?

Thanks a lot!!

David Smith · ‎12-21-2010

The fax server is sending a mid-call INVITE for T38 caps after the call has been answered and set up for voice...this is normal:

*Dec 15 14:46:38.242: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
INVITE sip:003039735299@192.168.5.12:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.254:5060;branch=z9hG4bK23dc69661df2b18001ada2f727bade2b
From: <192>;tag=466512b9
To: <003039735299>;tag=383EC3F8-45A
Call-Id: F3C53B38-79011E0-90FDAA09-A3FEB436@192.168.5.12
CSeq: 1 INVITE
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, REFER
Contact: <192>
Content-Type: application/sdp
Content-Length: 298
Max-Forwards: 70
Min-SE: 90
Record-Route: <192.168.1.254:5060>
Session-Expires: 1800
Supported: timer
User-Agent: www.te-systems.de XCAPI V3.3.161.0
X-XCAPI-UUID: D5EE2A8801CB9C06804323BE84E16CD6
X-Bearer-Capability: 3_1KHzAudio
P-Alcatel-CSBU: charging=<192>

v=0
o=sip 029 2 IN IP4 192.168.1.254
s=SIP session
c=IN IP4 192.168.1.254
t=0 0
m=image 1682 udptl t38
a=T38FaxVersion:0
a=T38MaxBitRate:14400
a=T38FillBitRemoval:0
a=T38FaxTranscodingMMR:0
a=T38FaxTranscodingJBIG:0
a=T38FaxRateManagement:transferredTCF
a=T38FaxUdpEC:t38UDPRedundancy

However the GW never responds to this mid-call INVITE with 100 Trying and 200 OK...so T38 negotiation fails and the fax server drops the call.

Can you provide a full debug, and full configs from the GW in question?

conf t

no logging console

logging buffered 10000000 debug

service sequence

debug isdn q931

debug voip ccapi inout

debug ccsip all

Also, a full running config.

Thanks

jordisuste · ‎12-29-2010

Hi,

Sorry for my delay, I was away.

I attach the debug and the full gateway configuration.

Thanks a lot!

David Smith · ‎12-29-2010

Looks good, for the most part.

The call connects, then the fax server sends a mid-call INVITE for T38:

020197: *Dec 29 09:30:42.492: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
INVITE sip:001603617809@192.168.5.12:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.254:5060;branch=z9hG4bK5f926e0e4ecda65a65c5184d8971c270
From: <192>;tag=0fb707e5
To: <001603617809>;tag=7F368BAC-1B7
Call-Id: 22A19DE5-126511E0-9066AA09-A3FEB436@192.168.5.12
CSeq: 1 INVITE
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, REFER
Contact: <192>
Content-Type: application/sdp
Content-Length: 301
Max-Forwards: 70
Min-SE: 90
Record-Route: <192.168.1.254:5060>
Session-Expires: 1800
Supported: timer
User-Agent: www.te-systems.de XCAPI V3.3.161.0
X-XCAPI-UUID: FCD4165501CBB70A804523BE84E16CD6
X-Bearer-Capability: 3_1KHzAudio
P-Alcatel-CSBU: charging=<192>

v=0
o=sip 122881 2 IN IP4 192.168.1.254
s=SIP session
c=IN IP4 192.168.1.254
t=0 0
m=image 1868 udptl t38
a=T38FaxVersion:0
a=T38MaxBitRate:14400
a=T38FillBitRemoval:0
a=T38FaxTranscodingMMR:0
a=T38FaxTranscodingJBIG:0
a=T38FaxRateManagement:transferredTCF
a=T38FaxUdpEC:t38UDPRedundancy

The GW sends 100 Trying, then 200 OK within 12 ms after receiving the mid-call INVITE:

020314: *Dec 29 09:30:42.504: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.1.254:5060;branch=z9hG4bK5f926e0e4ecda65a65c5184d8971c270
From: <192>;tag=0fb707e5
To: <001603617809>;tag=7F368BAC-1B7
Date: Wed, 29 Dec 2010 09:30:42 GMT
Call-ID: 22A19DE5-126511E0-9066AA09-A3FEB436@192.168.5.12
CSeq: 1 INVITE
Allow-Events: telephone-event
Server: Cisco-SIPGateway/IOS-12.x
Content-Length: 0

020315: *Dec 29 09:30:42.504: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.254:5060;branch=z9hG4bK5f926e0e4ecda65a65c5184d8971c270
From: <192>;tag=0fb707e5
To: <001603617809>;tag=7F368BAC-1B7
Date: Wed, 29 Dec 2010 09:30:42 GMT
Call-ID: 22A19DE5-126511E0-9066AA09-A3FEB436@192.168.5.12
CSeq: 1 INVITE
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
Allow-Events: telephone-event
Remote-Party-ID: <001603617809>;party=called;screen=yes;privacy=off
Contact: <001603617809>
Record-Route: <192.168.1.254:5060>
Supported: replaces

Supported: sdp-anat
Server: Cisco-SIPGateway/IOS-12.x
Session-Expires: 1800;refresher=uac
Require: timer
Content-Type: application/sdp
Content-Length: 157

v=0
o=CiscoSystemsSIP-GW-UserAgent 7716 1643 IN IP4 192.168.5.12
s=SIP Call
c=IN IP4 192.168.5.12
t=0 0
m=image 23226 udptl t38
c=IN IP4 192.168.5.12

The odd thing is the Fax Server sends another mid-call INVITE to the GW for T38 caps, only after waiting 12 MS.

It sends the mid-call INVITE again...before the GW ever receives the ACK for the first mid-call INVITE...and then right after, the GW receives the ACK, pertaining to the first 200 OK sent by the GW.

020319: *Dec 29 09:30:42.504: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
INVITE sip:001603617809@192.168.5.12:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.254:5060;branch=z9hG4bK5f926e0e4ecda65a65c5184d8971c270
From: <192>;tag=0fb707e5
To: <001603617809>;tag=7F368BAC-1B7
Call-Id: 22A19DE5-126511E0-9066AA09-A3FEB436@192.168.5.12
CSeq: 1 INVITE
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, REFER
Contact: <192>
Content-Type: application/sdp
Content-Length: 301
Max-Forwards: 70
Min-SE: 90
Record-Route: <192.168.1.254:5060>
Session-Expires: 1800
Supported: timer
User-Agent: www.te-systems.de XCAPI V3.3.161.0
X-XCAPI-UUID: FCD4165501CBB70A804523BE84E16CD6
X-Bearer-Capability: 3_1KHzAudio
P-Alcatel-CSBU: charging=<192>

v=0
o=sip 122881 2 IN IP4 192.168.1.254
s=SIP session
c=IN IP4 192.168.1.254
t=0 0
m=image 1868 udptl t38
a=T38FaxVersion:0
a=T38MaxBitRate:14400
a=T38FillBitRemoval:0
a=T38FaxTranscodingMMR:0
a=T38FaxTranscodingJBIG:0
a=T38FaxRateManagement:transferredTCF
a=T38FaxUdpEC:t38UDPRedundancy

336: *Dec 29 09:30:42.504: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
ACK sip:001603617809@192.168.5.12:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.254:5060;branch=z9hG4bKe793170cdc505eb58fe057f413310471
From: <192>;tag=0fb707e5
To: <001603617809>;tag=7F368BAC-1B7
Call-Id: 22A19DE5-126511E0-9066AA09-A3FEB436@192.168.5.12
CSeq: 1 ACK
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, REFER
Contact: <192>
Content-Length: 0
Max-Forwards: 70
Supported: timer
User-Agent: www.te-systems.de XCAPI V3.3.161.0
X-XCAPI-UUID: FCD4165501CBB70A804523BE84E16CD

Any idea why the fax server is sending another mid-call INVITE, after only waiting 12 ms...and before an ACK is sent? Is there a timer that will slow down the fax server so that it doesn't send the mid-call INVITE again so quickly?

There's no 488 error in the log, so that doesn't appear to be an issue.

I'm just wondering if there's a race condition going on with the fax server that is breaking fax.

The below debugs will tell us if T38 is in fact negotiated, and what's happening on the T30 side:

debug isdn q931

debug ccsip message

debug voip ccapi inout

debug fax relay t30 all

Thanks.

jordisuste · ‎12-29-2010

Hi David,

First of all, thanks a lot for your time and your troubleshooting. It is also helping me a lot for future issues.

I don't manage the server, but tomorrow morning (my time) I will get in touch with the people. Let's see what they say.

I attach the last debug. The test was a call to the fax. I ended the call after 30 seconds, as it was doing the same every 3 to 5 seconds.

Again, thanks a lot!!

David Smith · ‎12-29-2010

OK, so this one looks good now, I see the mid-call INVITE for T38, GW responds with 200 OK, then the GW receives and ACK...no more 2nd mid-call INVITE. This tells us the call negotiated T38 succesfully.

After the call switches to T38 I see T30 packets being TX, or sent, by the DSP to the originating fax machine:

021358: *Dec 29 22:09:36.345: 0/0/0:15 2179744735 fr-entered=10(ms)
    timestamp=2179750835 fr-msg-tx DIS
    timestamp=2179755925 fr-msg-tx DIS
    timestamp=2179761035 fr-msg-tx DIS
    timestamp=2179766135 fr-msg-tx DIS
    timestamp=2179771245 fr-msg-tx DIS
    timestamp=2179776355 fr-msg-tx DIS
    timestamp=2179781455 fr-msg-tx DIS

The TX is from the DSP perspective, it's sending them out from the DSP to the wire...or T1, this is coming from the fax server. If it were receiving T30 messages from the sending fax on the PSTN side they'd be marked with "fr-msg-rx".

I don't see any response coming back from the originating fax. If it were to respond we'd see a "DCS (Digital Command Signal)/TSI" message, followed by a TCF (Training Check). Then the receiving device would send CFR (Confirmation to Receive).

I don't see this happening though, the originating fax isn't sending any thing at all.

Here's a good link that displays the correct T30 call flow and message exchange:

http://www.cisco.com/en/US/customer/tech/tk652/tk777/technologies_tech_note09186a0080114565.shtml#topic4-1

Can you make calls from this fax server to any fax machine? Just a plain old G3 fax?

If not, you may want to open a TAC case to have this looked at.

Thanks

jordisuste · ‎12-29-2010

thanks again. I didn't have any fax with me so I just made a call. Tomorrow (in 9 hours) I will make a proper test. I will let you know again.

Cheers.

jordisuste · ‎01-17-2011

Hi Dave,

Finally the problem was solved adding those lines in the gateway:

sip-ua

retry invite 2

Thanks a lot for your help!!!