Incoming Fax over PSTN Issue

[andrevieira2]

Hi all,

We have replaced an old voice gateway Cisco 2811 with a new Cisco 4331 and "ported" more or less all relevant configuration from the old to the new.

All Calls incoming and outgoing are working fine to our phones. But the incoming Fax from external are not working.

It rings 1 time (arrives at our gateway) and then we hear nothing. The call stays connected but there is no fax sound as we normally expect.

If I call the fax internally (not going over Gateway), the fax does its well known sound and works.

And with the old gateway it also works.

Fax Number: +35020002501 

I've done many tests and configuration changes to test but had no luck till now. Below you can see all my debugs:

sh voice call status
CallID     CID  ccVdb      Port        Slot/Bay/DSP:Ch  Called #   Codec    MLPP Dial-peers
0x6E0EC    1388 0x7FFDA96E1740 0/1/0:15.1       1/1:1   5020002501 g711ulaw 10/500
1 active call found

Extract of the configuration:

...

voice service voip
 ip address trusted list
  ipv4 Server1
  ipv4 Server2
  ipv4 Server3
  ipv4 Server4
 allow-connections sip to sip
 no supplementary-service sip handle-replaces
 fax protocol t38 version 0 ls-redundancy 2 hs-redundancy 0 fallback pass-through g711ulaw
 modem passthrough nse codec g711ulaw
 sip
  bind control source-interface Loopback0
  bind media source-interface Loopback0
  registrar server
  no update-callerid
!        
voice class codec 10
 codec preference 1 g711ulaw
 codec preference 2 g711alaw
 codec preference 3 g729r8
!
!
voice class sip-profiles 1
 request INVITE sip-header From modify "<sip:anonymous@" "<sip:"
 request INVITE sip-header From modify "anonymous" ""
!
!
voice class server-group 100
 ipv4 Server1 preference 1
 ipv4 Server2 preference 2
 ipv4 Server3 preference 3
 ipv4 Server4 preference 4
 description UCM Server Group
!

...

!
voice translation-rule 20
 rule 1 /^2000\(....\)$/ /+3502000\1/
 rule 2 /^025\(..\)$/ /+350200025\1/
!
voice translation-rule 21
 rule 1 /^/ /+35020/ type subscriber subscriber
 rule 2 /^/ /+350/ type national national
 rule 3 /^/ /+/ type international international
!

...

!
voice translation-profile PSTN2ITN
 translate calling 21
 translate called 20
!

...

!
dial-peer voice 10 pots
 description PSTN Incoming Dialpeer
 translation-profile incoming PSTN2ITN
 call-block translation-profile incoming blacklisted-calls
 call-block disconnect-cause incoming call-reject
 preference 1
 incoming called-number .T
 direct-inward-dial
 port 0/1/0:15
!

...

!
dial-peer voice 500 voip
 description SIP to CUCM 
 preference 1
 destination-pattern +350200025..
 session protocol sipv2
 session transport tcp
 session server-group 100
 voice-class codec 10 
 voice-class sip options-keepalive profile 100
 voice-class sip bind control source-interface Loopback0
 voice-class sip bind media source-interface Loopback0
 dtmf-relay rtp-nte sip-notify
 fax-relay sg3-to-g3
 no vad
!

...

Extract of the relevant logs I've found.

Right before any Logs with the Calling and Called numbers show up I get this message:

Received:
SIP/2.0 503 Service Unavailable
Via: SIP/2.0/TCP ***GATEWAY LOOPBACK***:5060;branch=z9hG4bK44BE5D50
From: <sip:***GATEWAY LOOPBACK***>;tag=6111E241-D7C
To: <sip:***PUBLISHER IPADDRESS***>;tag=1149161109
Date: Wed, 04 Apr 2018 09:02:59 GMT
Call-ID: CE5B75F8-371D11E8-A979AD25-DD7BDD2E@10.50.66.1
CSeq: 101 OPTIONS
Warning: 399 ***PUBLISHER HOSTNAME*** "Unable to find a device handler for the request received on port 51036 from ***GATEWAY LOOPBACK***"
Content-Length: 0

This are the next logs:

...

Apr  4 11:03:04.343: ISDN Se0/1/0:15 Q931: RX <- SETUP pd = 8  callref = 0x0001
        Sending Complete
        Bearer Capability i = 0x9090A3
                Standard = CCITT
                Transfer Capability = 3.1kHz Audio
                Transfer Mode = Circuit
                Transfer Rate = 64 kbit/s
        Channel ID i = 0xA98381
                Exclusive, Channel 1
        Progress Ind i = 0x8381 - Call not end-to-end ISDN, may have in-band info 
        Progress Ind i = 0x8483 - Origination address is non-ISDN 
        Calling Party Number i = 0x1183, '41797329xxx' *** My mobile number
                Plan:ISDN, Type:International
        Called Party Number i = 0xC1, '02501'
                Plan:ISDN, Type:Subscriber(local)
Apr  4 11:03:04.343: ISDN Se0/1/0:15 Q931: Received SETUP  callref = 0x8001 callID = 0x01C0 switch = primary-net5 interface = User

...

Dial Peer matching....

...

Apr  4 11:03:04.353: //447699/D183693D818E/SIP/Info/critical/32768/ccsip_ipip_media_forking_update_preferred_codec: MF: Not a Forked SIP leg..
Apr  4 11:03:04.353: //447699/D183693D818E/SIP/Info/info/8704/sipSPIGetCallConfig: Incoming: No defer BYE for last
                              call stats
Apr  4 11:03:04.353: //447699/D183693D818E/SIP/Info/verbose/1/ccsip_set_srtp_config: No Srtp configure for this leg.
Apr  4 11:03:04.353: //447699/D183693D818E/SIP/Info/info/8192/sipSPIGetCallConfig: Media forking disabled
Apr  4 11:03:04.353: //447699/D183693D818E/SIP/Info/info/34816/ccsip_ipip_media_forking_anchor_leg_config: MF: en_p->encap_s.voIP.voipPeerCfgMediaClass = 0
Apr  4 11:03:04.353: //447699/D183693D818E/SIP/Info/info/34816/ccsip_ipip_media_forking_anchor_leg_config: MF: Dial-peer has no media class recorder.
Apr  4 11:03:04.353: //447699/D183693D818E/SIP/Info/info/36864/sipSPIMFChangeState: MF: Prev state = 0 & New state = -1
Apr  4 11:03:04.353: //447699/D183693D818E/SIP/Info/info/32768/ccsip_ipip_media_forking_anchor_leg_reset: MF: Anchor leg config reset done...
Apr  4 11:03:04.353: //447699/D183693D818E/SIP/Info/info/32768/ccsip_ipip_media_forking_intra_frame_request_config: MF: FIR en_p->encap_s.voIP.voipPeerCfgMediaClass = 0
Apr  4 11:03:04.353: //447699/D183693D818E/SIP/Info/info/32768/ccsip_ipip_media_forking_get_forked_leg_config: MF: This leg is not forked call leg.
Apr  4 11:03:04.353: //447699/D183693D818E/SIP/Info/critical/11264/ccsipInitDSCPPolicyInfo: No DSCP Profile configured, No RPH 2 DSCP Mapping and DSCP policing
Apr  4 11:03:04.353: //447699/D183693D818E/SIP/Info/verbose/8192/sipSPIGetCallConfig: Initilise the DSCP policy
Apr  4 11:03:04.353: //447699/D183693D818E/SIP/Info/verbose/8192/sipSPICheckFAAnatAssymetricOrDO2EO: Not a SIP-SIP call or not in FA mode
Apr  4 11:03:04.353: //447699/D183693D818E/SIP/Info/notify/2049/populate_vcc_data: Using Voice Class Codec, tag = 10 and offer-all is = FALSE
Apr  4 11:03:04.353: //447699/D183693D818E/SIP/Info/notify/8192/sipSPISetOverlapConfiguration: Overlap signaling: FALSE: Endpt: SIP Trunk
Apr  4 11:03:04.353: //447699/D183693D818E/SIP/Info/verbose/10240/sipSPI_ipip_GetHdrPassthruCfg: Hdr passthrough config:1 tag:0
Apr  4 11:03:04.353: //447699/D183693D818E/SIP/Info/verbose/2048/sipSPI_ipip_GetCopyListCfg: Copy-list config:2 tag:0
Apr  4 11:03:04.353: //447699/D183693D818E/SIP/Info/info/2048/sipSPIGetExtensionCfg: SIP extension config:1, check sys cfg:1
Apr  4 11:03:04.353: //447699/D183693D818E/SIP/Info/notify/10240/sipSPI_ipip_build_consolidated_header_list: Both passthru and copylist are disabled
Apr  4 11:03:04.353: //447699/D183693D818E/SIP/Info/info/1/preprocessSetup:
 This is a not a SIGO Call -, could be DM call
Apr  4 11:03:04.354: //447699/D183693D818E/SIP/State/ccsip_cnfsm_debugs: IWF:cur_container:sip_iwf_default_early_dialog_container, cur_state:S_SIP_IWF_SDP_IDLE, event:E_SIP_IWF_EV_INIT_CALL_SETUP
Apr  4 11:03:04.354: //447699/D183693D818E/SIP/State/ccsip_cnfsm_debugs: IWF:new_container:sip_iwf_main_container
Apr  4 11:03:04.354: //447699/D183693D818E/SIP/Info/verbose/4096/ccsip_iwf_process_event: IWF - cnfsm ret 2
Apr  4 11:03:04.354: //447699/D183693D818E/SIP/Info/notify/4096/preprocessSetup: SIP-TDM or TCL/VXML app case
Apr  4 11:03:04.354: //447699/D183693D818E/SIP/Info/notify/6/sipSPIValidateStreamAddrType: stream:1, Mode : 1
Apr  4 11:03:04.354: //447699/D183693D818E/SIP/Info/verbose/513/resolve_media_ip_address_to_bind: peer_tag=500
Apr  4 11:03:04.354: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_media_ip_address_to_bind: VRF id = 0
Apr  4 11:03:04.354: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/ccsip_get_ifaddress: ip_address IPv4 ***GATEWAY LOOPBACK*** for SIP
Apr  4 11:03:04.354: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_ip_address_to_bind: ip_get_ifaddress IPv4 ***GATEWAY LOOPBACK*** for SIP
Apr  4 11:03:04.354: //447699/D183693D818E/SIP/Media/sipSPISetMediaSrcAddr: Media src addr for stream 1 = ***GATEWAY LOOPBACK***
Apr  4 11:03:04.354: //447699/D183693D818E/SIP/Info/critical/1/sipSPIOutgoingCallSDP: Failure in creating outbound streams
SIP: (447699) Group (a= group line) attribute, level 65535 instance 1 not found.
Apr  4 11:03:04.354: //447699/D183693D818E/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: VRF id = 0
Apr  4 11:03:04.354: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/ccsip_get_ifaddress: ip_address IPv4 ***GATEWAY LOOPBACK*** for SIP
Apr  4 11:03:04.354: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_ip_address_to_bind: ip_get_ifaddress IPv4 ***GATEWAY LOOPBACK*** for SIP
Apr  4 11:03:04.354: //447699/D183693D818E/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: signaling bind address : ***GATEWAY LOOPBACK***
Apr  4 11:03:04.354: //-1/xxxxxxxxxxxx/SIP/Info/info/8192/resolve_sig_ip_address_to_bind: return addr ***GATEWAY LOOPBACK***
Apr  4 11:03:04.354: //-1/xxxxxxxxxxxx/SIP/Media/sipSPIReserveRtpPort: reserved port 19828 for stream 1
Apr  4 11:03:04.354: //447699/D183693D818E/SIP/Info/info/1/sipSPIDoBearerCapToCodecMapping: Bearer capability to Codec Mapping: DISABLED

Apr  4 11:03:04.354: //447699/D183693D818E/SIP/Media/sipSPIAddSDPMediaPayload: Preferred method of dtmf relay is: 6, with payload: 101
Apr  4 11:03:04.354: //447699/D183693D818E/SIP/Info/info/131074/sipSPIBwCacCalcMaxAudioBandwidth: calculating max bw from preffered codecs (local offer)
SIP: (447699) Group (a= group line) attribute, level 65535 instance 1 not found.
Apr  4 11:03:04.354: //447699/D183693D818E/SIP/Info/info/131074/sipSPIBwCacCalcMaxAudioBandwidth: max bw (excluding pak overhead) from preffered codecs: codec g711ulaw  bw 64000        index 0
Apr  4 11:03:04.354: //447699/D183693D818E/SIP/Info/critical/2/sipSPIBwCacCalcMaxAudioBandwidth: audio caps channel idx not found !!!!
Apr  4 11:03:04.354: //-1/xxxxxxxxxxxx/SIP/Info/notify/1/convert_codec_bytes_to_ptime: Values :Codec: g711ulaw codecbytes :160, ptime: 20
Apr  4 11:03:04.442: //-1/xxxxxxxxxxxx/SIP/Info/critical/1024/httpish_msg_process_network_msg: HEADER LINE READ FAILURE DUE TO RS->EOF
Apr  4 11:03:04.442: //-1/xxxxxxxxxxxx/SIP/Info/critical/1024/ccsip_process_network_message: process_network_msg: not complete
Apr  4 11:03:04.442: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x7FFDB30983B0
Apr  4 11:03:04.442: //-1/xxxxxxxxxxxx/SIP/Info/critical/4096/sip_tcp_newmsg_to_spi: process_network_msg: not complete
Apr  4 11:03:04.442: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x7FFDB3098A28
Apr  4 11:03:04.484: //-1/xxxxxxxxxxxx/SIP/Transport/sip_find_connid_by_fd: Map fd 7 to index 65

...

I tried to search this error messages but had no luck.

Do you know anything I could try to solve this issue? Or do you need more debugs?

Thanks all for any help!

[andrevieira2]

If I only do a "debug isdn q931" I get this message:

Apr  6 09:41:53.717: ISDN Se0/1/0:15 Q931: RX <- SETUP pd = 8  callref = 0x0001
        Sending Complete
        Bearer Capability i = 0x8090A3
                Standard = CCITT
                Transfer Capability = Speech 
                Transfer Mode = Circuit
                Transfer Rate = 64 kbit/s
        Channel ID i = 0xA98381
                Exclusive, Channel 1
        Progress Ind i = 0x8381 - Call not end-to-end ISDN, may have in-band info 
        Progress Ind i = 0x8483 - Origination address is non-ISDN 
        Calling Party Number i = 0x1183, '41797329888'
                Plan:ISDN, Type:International
        Called Party Number i = 0xC1, '02501'
                Plan:ISDN, Type:Subscriber(local)
Apr  6 09:41:53.717: ISDN Se0/1/0:15 Q931: Received SETUP  callref = 0x8001 callID = 0x01E7 switch = primary-net5 interface = User
Apr  6 09:41:53.724: ISDN Se0/1/0:15 Q931: TX -> CALL_PROC pd = 8  callref = 0x8001
        Channel ID i = 0xA98381
                Exclusive, Channel 1
Apr  6 09:41:53.806: ISDN Se0/1/0:15 Q931: TX -> ALERTING pd = 8  callref = 0x8001
Apr  6 09:41:53.854: ISDN  **ERROR**: validate_connected_number: Invalid connected_number
Apr  6 09:41:53.854: ISDN Se0/1/0:15 Q931: TX -> CONNECT pd = 8  callref = 0x8001

I've checked the translations and even the traffic. It's a RightFax. I can see traffic from the Gateway to the Rightfax server. All looks really good. Just the problem that the fax is muted and cannot receive faxes like this.

Thanks for any help.

[R0g22]

Are your voice calls working fine with two way audio ? Also, the rightfax is integrated with CUCM or gateway directly ?

Edit: What is the destination configured on the CUCM SIP trunk ? Is it the router loopback IP ?

[narinder sandhu]

Hi Could you please upload the entire sip trace from invite to termination from the gateway.

question:

The 503 response was it  received by the gateway from CUCM?

503 message is indicating the service is unavailable.

if we look at the ccm traces please could you upload the entire trace from cucm with the invite to this response being sent?

could you advise of the entire call flow:

TDM->gateway->sip cucm-> cucm sip to fax server?

it would also be interesting to see how cucm is communicating to the fax server in the b2bua role.

does the right fax server receive a invite request from cucm and does it respond?

do you have options ping enabled?

thanks

Narinder

Thanks

Narinder 

[andrevieira2]

Dear Nipun and Narinder,

First, thank you for your responses and your time.

Nipun, to your questions:

- Good point! I've done a test last friday to a normal phone and we get the same q931 error! But it works anyway. So we can heanr and the other side hears us also. So the issue is happening not only to rightfax.

- The RightFax is connected to the Call Manager directly with a Sip Trunk. We have many many faxes working over this without issues. Only Gibraltar has the problem.

- Correct, the destination of the CUCM->Gateway is to the Loopback address.

Narinder, to your questions:

- Correct, the 503 Response is received by the Gateway from CUCM.

- I've uploaded a complete trace from the Gateway calling a Phone (2523)and calling a Fax (2501).

- Correct. That is the route the Call does - PSTN->gateway->sip cucm-> cucm sip to fax server

- Yes I can see traffic outgoing and incoming from the CUCM to the RightFax. As I said before it's working for many other sites.

- "Options Ping" is not enabled.

The Traces are attached. Hopefully you can see something.

The logs are from external mobile phone to the Fax and to a Phone in Gib:

- debug isdn error

- debug isdn q931

- sh cssip messages all

Thanks!

[narinder sandhu]

Sorry I've been busy today so please excuse me for the delayed feedback.

thanks so the first part the 503 error seems to be related to a options message sent from the gateway:

Apr  9 10:10:48.023: //556181/000000000000/SIP/Msg/ccsipDisplayMsg:
Sent:
OPTIONS sip:10.1.192.132:5060 SIP/2.0
Via: SIP/2.0/TCP 10.50.66.1:5060;branch=z9hG4bK56C7C1308
From: <sip:10.50.66.1>;tag=7AA1E7AF-1FAB
To: <sip:10.1.192.132>
Date: Mon, 09 Apr 2018 08:10:48 GMT
Call-ID: 582F8EDB-3B0411E8-93DFAD25-DD7BDD2E@10.50.66.1
User-Agent: Cisco-SIPGateway/IOS-15.4.3.S4
Max-Forwards: 70
CSeq: 101 OPTIONS
Contact: <sip:10.50.66.1:5060;transport=tcp>
Content-Length: 0

so the request method was sent to the ip address 10.1.192.132

Received:
SIP/2.0 503 Service Unavailable
Via: SIP/2.0/TCP 10.50.66.1:5060;branch=z9hG4bK56C7C1308
From: <sip:10.50.66.1>;tag=7AA1E7AF-1FAB
To: <sip:10.1.192.132>;tag=2002442784
Date: Mon, 09 Apr 2018 08:10:48 GMT
Call-ID: 582F8EDB-3B0411E8-93DFAD25-DD7BDD2E@10.50.66.1
CSeq: 101 OPTIONS
Warning: 399 CH-SV01777 "Unable to find a device handler for the request received on port 51036 from 10.50.66.1"
Content-Length: 0

we received this response? can we investigate why this device responded with a 503.

the cucm sends a reinvite to the gateway with the fax settings in the sdp.

Received:
INVITE sip:+41797329888@10.50.66.1:5060;transport=tcp SIP/2.0
Via: SIP/2.0/TCP 10.1.128.135:5060;branch=z9hG4bK8f4211138ed32d
From: <sip:+35020002501@10.1.128.135>;tag=20448815~066d7f19-322a-43ba-8eca-ef58947b04ca-62721385
To: <sip:+41797329888@10.50.66.1>;tag=7AA1D189-2377
Date: Mon, 09 Apr 2018 08:10:45 GMT
Call-ID: 54CE3B25-3B0411E8-93DEAD25-DD7BDD2E@10.50.66.1
Supported: timer,resource-priority,replaces
Cisco-Guid: 1422721597-0990122472-2178599958-2120343360
User-Agent: Cisco-CUCM10.5
Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY
CSeq: 101 INVITE
Max-Forwards: 70
Expires: 180
Allow-Events: presence
Call-Info: <urn:x-cisco-remotecc:callinfo>;x-cisco-video-traffic-class=MIXED
Supported: X-cisco-srtp-fallback
Supported: Geolocation
Session-Expires:  14400;refresher=uac
Min-SE:  1800
P-Preferred-Identity: <sip:+35020002501@10.1.128.135>
Remote-Party-ID: <sip:+35020002501@10.1.128.135>;party=calling;screen=no;privacy=off
Contact: <sip:+35020002501@10.1.128.135:5060;transport=tcp>
Content-Type: application/sdp
Content-Length: 363

v=0
o=CiscoSystemsCCM-SIP 20448815 2 IN IP4 10.1.128.135
s=SIP Call
c=IN IP4 10.1.100.45
t=0 0
m=image 56340 udptl t38
a=T38FaxVersion:3
a=T38MaxBitRate:9600
a=T38FaxFillBitRemoval:0
a=T38FaxTranscodingMMR:0
a=T38FaxTranscodingJBIG:0
a=T38FaxRateManagement:transferredTCF
a=T38FaxUdpEC:t38UDPRedundancy
a=T38FaxMaxBuffer:200
a=T38FaxMaxDatagram:72

I do not see any response clearly go back to the cucm after this re-invite request. again I may have missed something here.

a bit further down I notice a another options request this looks like it came in from cucm.

Received:
OPTIONS sip:10.50.66.1:5060 SIP/2.0
Via: SIP/2.0/TCP 10.1.128.135:5060;branch=z9hG4bK8f422472638a2a
From: <sip:10.1.128.135>;tag=1996443022
To: <sip:10.50.66.1>
Date: Mon, 09 Apr 2018 08:10:49 GMT
Call-ID: 81f69000-acb12009-4dd38f-8780010a@10.1.128.135
User-Agent: Cisco-CUCM10.5
CSeq: 101 OPTIONS
Contact: <sip:10.1.128.135:5060;transport=tcp>
Max-Forwards: 0
Content-Length: 0

here is the response sent from the gateway to this options request: 

Apr  9 10:10:49.287: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 200 OK
Via: SIP/2.0/TCP 10.1.128.135:5060;branch=z9hG4bK8f422472638a2a
From: <sip:10.1.128.135>;tag=1996443022
To: <sip:10.50.66.1>;tag=7AA1EC9D-2545
Date: Mon, 09 Apr 2018 08:10:49 GMT
Call-ID: 81f69000-acb12009-4dd38f-8780010a@10.1.128.135
Server: Cisco-SIPGateway/IOS-15.4.3.S4
CSeq: 101 OPTIONS
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
Allow-Events: telephone-event
Accept: application/sdp
Supported: 100rel,timer,resource-priority,replaces,sdp-anat
Content-Type: application/sdp
Content-Length: 365

v=0
o=CiscoSystemsSIP-GW-UserAgent 6372 7849 IN IP4 10.50.66.1
s=SIP Call
c=IN IP4 10.50.66.1
t=0 0
m=audio 0 RTP/AVP 18 0 8 9 4 2 15 3
c=IN IP4 10.50.66.1
m=image 0 udptl t38
c=IN IP4 10.50.66.1
a=T38FaxVersion:0
a=T38MaxBitRate:9600
a=T38FaxRateManagement:transferredTCF
a=T38FaxMaxBuffer:200
a=T38FaxMaxDatagram:320
a=T38FaxUdpEC:t38UDPRedundancy

shortly after we receive the disconnect form the ISDN circuit:

Apr  9 10:10:49.287: //-1/xxxxxxxxxxxx/SIP/Info/info/1024/httpish_msg_free: Freed msg=0x7FFDA4A8D9B0
Apr  9 10:10:49.734: ISDN Se0/1/0:15 Q931: RX <- DISCONNECT pd = 8  callref = 0x0001
        Cause i = 0x8490 - Normal call clearing
        Progress Ind i = 0x8288 - In-band info or appropriate now available

also could you try adding voice iec syslog to the global configuration of the router. i'd  alos like you add some specific debugs just to get a final trace.

so please undebug all,

then enable:

debug ccsip messages

debug isdn q931

debug ccapi inout

and as mentioned earlier please enable the voice iec syslog global config command.

also could you send me a show run and show version.

I haven't had to check the cucm to fax server logs yet I'll do this tomorrow.

thanks

Narinder

[R0g22]

Check and confirm what is the IP address on the CUCM SIP trunk ? From the logs, I never see a dialog being established post a INVITE. The CUCM sends a RE-INVITE even before a dialog is established which is incorrect. Your faxes won't work until and unless there is a voice call established first.
Your logs that contain the IP phone call has a dialog established.

Now, I think the router is dropping logs if you are taking the logs on the terminal since you have ccsip all enabled which is very very chatty.

For a fax call, enable only the following logs and take them in a buffer -

debug ccsip message
debug ccsip error
debug isdn q931
debug voip vtsp all
debug voice ccapi inout

Also check your TDM controller and ensure there are no slips.

[andrevieira2]

Hi Guys,

Thanks for your replies!

Okay, as you say there is really something strange since the gateway is not replying to the first connection request.

Narinder, I've added the command voice iec syslog to the global config.

Attached are the Sh Run and sh version. And also a call trace to the fax with the following debug commands:

- debug ccsip message
- debug ccsip error
- debug isdn q931
- debug voip vtsp all
- debug voice ccapi inout

Thanks for helping! 

Regards,

André

[R0g22 · Accepted solution]

From a fax perspective I don't see anything wrong yet.

*/ T38 start -

Apr 10 09:55:05.040: //577853/4EB1410181F3/CCAPI/cc_api_t38_fax_start:
Destination Interface=0x7FFDA96E1740, Destination Call Id=577852, Source Call Id=577853,
Caps(Codec=T38Fax(0x10000), Fax Rate=FAX_RATE_9600(0x20),Fax Version:=0, Vad=OFF(0x1),
Modem=OFF(0x0), Codec Bytes=20, Signal Type=2)

*/ Download tone event -

Apr 10 09:55:05.042: //577852/4EB1410181F3/VTSP:(0/1/0:15):0:1:1/vtsp_dsm_peer_event_cb:
Event=E_DSM_CC_MC_LOCAL_DNLD_DONE

*/ Event done -

Apr 10 09:55:05.099: //577852/4EB1410181F3/VTSP:(0/1/0:15):0:1:1/vtsp_process_event:
[state:S_CONNECT, event:E_CC_T38_REMOTE_DNLD_DONE]


*/ Your telco disconnects the call -

Apr 10 09:55:21.295: ISDN Se0/1/0:15 Q931: RX <- DISCONNECT pd = 8 callref = 0x0001
Cause i = 0x8A90 - Normal call clearing
Progress Ind i = 0x8288 - In-band info or appropriate now available

Add the following to the dial-peer 500 please -

dial-peer voice 500 voip
fax protocol t38 ls-redundancy 0 hs-redundancy 0 fallback pass-through g711ulaw
fax-relay ecm disable
fax nsf 000000
fax-relay sg3-to-g3

Before testing another fax enable an additional debug - "debug fax relay t30 all".

Did you confirm that your TDM circuit does not have any slips ?

[narinder sandhu]

I have looked through the sip trace and there is no problem in the sip communication the call establishes correctly but i think the issue is with the fax tones.

 the original trace didn't contain the entire sip trace.

yes agreed with nipun please add the above config from 

dial-peer voice 500 voip
fax protocol t38 ls-redundancy 0 hs-redundancy 0 fallback pass-through g711ulaw
fax-relay ecm disable

fax nsf 000000
fax-relay sg3-to-g3 

again sorry for the slow response.

[andrevieira2]

Dear Nipun and Narinder,

Sorry that I did not answer before. We had an external guy here yesterday for another topic and we used the time and asked him regarding this issue.

Before this, we checked if we had any slips. And we really had some Slip secs. So we played a bit with the clock configuration until this was stable.

Then we tested:

dial-peer voice 500 voip
fax protocol t38 ls-redundancy 0 hs-redundancy 0 fallback pass-through g711ulaw
fax-relay ecm disable

fax nsf 000000
fax-relay sg3-to-g3 

This did also not work.

Then the external had the idea to change the fax protocol with version 3.

So now the dialpeer looks like this:

dial-peer voice 500 voip
 description SIP to CUCM 
 preference 1
 destination-pattern +350200025..
 session protocol sipv2
 session transport tcp
 session server-group 100
 voice-class codec 10 
 voice-class sip options-keepalive profile 100
 voice-class sip bind control source-interface Loopback0
 voice-class sip bind media source-interface Loopback0
 dtmf-relay rtp-nte sip-notify
 fax-relay ecm disable
 fax-relay sg3-to-g3
 fax rate 9600
 fax nsf 000000
 fax protocol t38 version 3 ls-redundancy 0 hs-redundancy 0 fallback pass-through g711ulaw
 no vad

And this FINALLY WORKS! Incredible how hard this was!

Thanks to both of you for all the support! :)