Guest

Fax / Modem over IP

T.37 OnRamp Faxing

Document ID: 47763

Updated: Feb 02, 2006

   Print

Introduction

This section of the main Fax over IP T.37 Store and Forward Fax document describes OnRamp store-and-forward faxing. OnRamp T.37 is the process of accepting a fax call, encoding that fax into a Tagged Image File Format (TIFF), and sending that TIFF to an email server as an attachment.

This document contains the configuration required to get the feature operational. The Troubleshoot section goes over the useful debug commands and how to interpret their meaning. The topology used is shown in the Network Diagram section.

Prerequisites

Requirements

The specific requirements for this document are specified in the main section, Fax over IP T.37 Store and Forward Fax.

Components Used

This document is not restricted to specific software and hardware versions.

The information in this document was created from the devices in a specific lab environment. All of the devices used in this document started with a cleared (default) configuration. If your network is live, make sure that you understand the potential impact of any command.

Conventions

For more information on document conventions, refer to the Cisco Technical Tips Conventions.

Configuration

In the sections below, first the Cisco IOS® Software configuration parameters relevant to OnRamp fax configuration are explained, and then the 5300 configuration is displayed with further notes clarifying the functions of important commands. Some optional configuration parameters can be found in the section that follows the 5300 configuration.

Network Diagram

This document uses the network setup shown in the diagram below.

onramp_faxing1.gif

Configuration Parameters

Mandatory parameters:
fax interface-type fax-mail Enables T.37 functionality for the gateway. Requires a reboot on the 5300, but not the 5350 or 5400.
mta send server This is the hostname or IP address of the Simple Mail Transfer Protocol (SMTP) server the router is going to send the OnRamp email through. Without this configuration, the router does not know where to send OnRamp email. See the No server configured section for debugs and console messages without the server configured.
mta send postmaster This address is used if mta sent mail-from options do not evaluate or are not configured. It is placed in OnRamp email From field. This is optional if mta send mail-from username and mta send mail-from hostname are present. Click here for debug mspi for a failed call.
ip domain-name Used to identify email sender in HELO message with hostname.domain-name. The router must be reloaded after this command is configured.
call application voice onramp flash:app_libretto_onramp.2.0.1.1.tcl Defines a global name for the application (onramp, in this case) and its location (in the router's flash, in this case).
dial-peer voice 8913180 pots application onramp Calls application onramp when this dial-peer is matched.
dial-peer voice 1 mmoip application fax_on_vfc_onramp_app out-bound Application to be called when this Multimedia Mail over IP (MMoIP) peer is matched. Pre-bundled in Cisco IOS Software. Visible through show call application voice summary.
Optional parameters:
mta send mail-from hostname This is the hostname to be used in the From field in the OnRamp email. Mandatory if the mta send postmaster command is not present. Must be configured if mta send mail-from username is used.
mta send mail-from username This is the originator to be used in the From field in the OnRamp email. Used in conjunction with mta send mail-from hostname to get entire From field—that is, username@hostname. Mandatory if the mta send postmaster command is not present. Must be configured if mta send mail-from hostname is used.
mta send subject Text string to be used in the Subject field in the OnRamp email.
mta send with-subject
  • Appends the calling party number with keyword $s$.
  • Appends the called party number with keyword $d$.
  • Appends both the calling and called party number with keyword both.
For debug display, click here.
mta send return-receipt-to Keywords are username and hostname. Together they form the disposition-notification-to:username@hostname.
dial-peer voice number mmoip mdn Requests that an email sent through this MMoIP peer requests an message disposition notification (MDN) be sent to the desitnation definted by the mta send return-receipt-to command.
dial-peer voice number mmoip dsn {delay | success | failure} Requests that a delivery status notice (DSN) be sent to the destination defined by the mta send mail-from command

OnRamp Configuration

vdtl-5300-7a# show running-config 
Building configuration...

Current configuration : 2294 bytes
!
! Last configuration change at 10:49:16 EST Mon Mar 18 2003
! NVRAM config last updated at 11:00:42 EST Mon Mar 4 2003
!
version 12.2
service timestamps debug datetime msec localtime
service timestamps log datetime msec localtime
no service password-encryption
!
hostname vdtl-5300-7a
!
!
resource-pool disable
clock timezone EST -5
!
ip subnet-zero
ip domain-name testlab-t37.com

!--- The ip domain-name command is needed so the router sends a fully qualified
!--- domain-name (FQDN) to the email server.
  

!--- Router must be reloaded after ip domain-name configuration due to a known bug
!--- that has since been resolved.

ip name-server 172.18.106.36

!--- The ip name-server command is required in order to do name resolution.

!
!
isdn switch-type primary-5ess
!
fax receive called-subscriber 8913180
fax interface-type fax-mail
! 
mta send server testlab-smtp.testlab-t37.com port 25

!--- The mta send server command identifies the email server for OnRamp emails.
 
! 
mta send subject Fax from On-Ramp GW vdlt-5300-7a
mta send with-subject both
mta send postmaster administrator@testlab-t37.com
!

!--- The address set with mta send postmaster is used as the "From" address
!--- unless mta send mail-from commands are defined.
 
! 
mta send mail-from hostname vdtl-5300-7a.testlab-t37.com
mta send mail-from username $s$
mta send return-receipt-to hostname testlab-t37.com
mta send return-receipt-to username admin
mta receive maximum-recipients 0
call-history-mib retain-timer 500
!
controller T1 0
framing esf
clock source line primary
linecode b8zs
pri-group timeslots 1-24
!
!
!
interface Ethernet0
ip address 15.80.7.11 255.255.255.0
!
interface Serial0:23
no ip address
isdn switch-type primary-5ess
isdn incoming-voice modem
no cdp enable
!
ip classless
ip route 0.0.0.0 0.0.0.0 15.80.7.1
no ip http server
ip pim bidir-enable
!
call rsvp-sync
!
call application voice onramp flash:app_libretto_onramp.2.0.1.1.tcl

!--- This identifies the call application to use. It is named "onramp" in
!--- this example.

voice-port 0:D 
!
mgcp profile default
!
dial-peer voice 1 mmoip
application fax_on_vfc_onramp_app out-bound
destination-pattern 8913144
information-type fax
session target mailto:$d$@testlab-t37.com 
!

!--- The MMoIP peers contain configuration specific to the called party number.
!--- It requests MDN and DSN. It identifies the application to use for the outbound
!--- call leg and specifies the address to which the email will be sent.
 
mdn
dsn success
dsn failure
! 
dial-peer voice 891314 pots
application onramp
incoming called-number 891314[4-5]
direct-inward-dial
port 0:D

!--- The pots peers for T.37 are no different than for voice calls with the exception of
!--- using the application defined above in the call application global configuration
!--- command. The direct-inward-dial command is required unless using a redialer.

!
line con 0
exec-timeout 0 0
line aux 0
line vty 0 4
login
!
ntp clock-period 17179806
ntp server 172.18.106.15
end

vdtl-5300-7a#

Optional Configuration

Here are some optional configuration parameters. The first example shows you how to configure multiple email accounts using traditional email addresses, and the second example shows you how to configure multiple email accounts using called party numbers for email addresses.

Example 1:

!
dial-peer voice 1 mmoip
 application fax_on_vfc_onramp_app out-bound
 destination-pattern 8913144
 information-type fax
 session target mailto:andy@testlab-t37.com
!
dial-peer voice 2 mmoip
 application fax_on_vfc_onramp_app out-bound
 destination-pattern 8913145
 information-type fax
 session target mailto:bobby@testlab-t37.com
!
dial-peer voice 891314 pots
 application onramp
 incoming called-number 891314[4-5]
 direct-inward-dial
 port 0:D
!
In this configuration, the PRI has two Direct Inward Dialing (DID) numbers: 891-3144 and 891-3145. Depending on which number is dialed, an email is sent either to andy@testlab-t37.com or to bobby@testlab-t37.com.

Example 2:

!
dial-peer voice 1 mmoip
application fax_on_vfc_onramp_app out-bound
destination-pattern 8913144
information-type fax
session target mailto:$d$@testlab-t37.com
!
With this configuration, the Dialed Number Identification Service (DNIS) (called party number) is inserted into the RCPT TO: SMTP command. This allows customers to give each user a DID for OnRamp applications. They simply add an alias on the email server. Mar 12 15:42:12.947: (C)S: RCPT TO:<FAX=8913144@testlab-t37.com>

Note: Make sure the email alias is FAX=8913144@domain.com instead of 8913144@domain.com or the email will not be delivered properly.

Troubleshoot

Failed Debugs

Note: Configuration changes are noted above the debugs.

debug mspi send
!
fax interface-type fax-mail
mta send server testlab-smtp.testlab-t37.com port 25
mta send mail-from hostname whatever.com
mta receive maximum-recipients 0
call-history-mib retain-timer 500
! 

Note: The mta send mail-from username command is omitted from the configuration, as is the mta send postmaster command.

vdtl-5300-7a#
Mar 4 10:03:29.165: mspi_setup_req: for cid=0x27
Mar 4 10:03:29.165: envelope_from=FAX=@        
!--- Note: This is not a valid email address (no domain).

Mar 4 10:03:29.165: envelope_to=andy@testlab-t37.com
Mar 4 10:03:30.165: mspi_chk_connect: cid=0x27, cnt=0, 
Mar 4 10:03:30.165: SMTP connected to the server !  
!--- The connection to the SMTP server is initiated.

Mar 4 10:03:30.165: mspi_bridge: cid=0x27, dst cid=0x28,
Mar 4 10:03:56.985: mspi_xmit: cid=0x27, st=CONFERENCED, src_cid=0x28, buf cnt=0
Mar 4 10:03:56.985: %MSPI-4-MSPI_NO_SMTP_SEND: MSPI- Could not
 send data to the SMTP server, cid=39, mspi_on_xmit, lost connection
Mar 4 10:03:56.985: mspi_on_xmit: cid=0x27, lost connection
Mar 4 10:03:56.985: disc text=no route to destination (3): SMTP client engine
 lost connection  
!--- The statement "no route to destination" is a little misleading as a cause code.

Mar 4 10:03:56.985: mspi_xmit: cid=0x27, st=ABORTING, src_cid=0x28
Mar 4 10:03:56.985: discarding buffer

!--- Several lines of mspi_xmit debugs that were identical to the lines above
!--- and below this note have been suppressed.

Mar 4 10:03:56.989: mspi_xmit: cid=0x27, st=ABORTING, src_cid=0x28
Mar 4 10:03:56.993: discarding buffer
Mar 4 10:03:56.993: %LAPP_ON_MSGS-6-LAPP_ON_CAUSE_NO_ESMTP_CONNECT: ESMTP client
 did not connect or lost connection to remote server
Mar 4 10:03:56.993: mspi_bridge_drop: cid=0x27, dst cid=0x28, st=ABORTING, onramp
Mar 4 10:03:56.993: mspi_disconnect: cid=0x27, st=DISCONNECTING, cause=no route to
 destination (3)
Mar 4 10:03:56.993: mspi_on_call_hist: cid=0x27, cause=no route to destination (3):
 SMTP client engine lost connection
Mar 4 10:03:56.993: disposing smtp ctx
Mar 4 10:03:56.993: mspi_free_ccb: mmccb allocated=1, inserted=0
vdtl-5300-7a#

The same problem can be seen a little clearer with this debug:

vdtl-5300-7a# debug mta send all
Mar 5 16:48:46.420: esmtp_client_engine_open: from=FAX=@, to=andy@testlab-t37.com
Mar 5 16:48:46.420: esmtp_client_engine_add_headers: from_comment=Fax 
Mar 5 16:48:46.792: esmtp_client_work: socket 0 attempting to connect to IP
 address 172.18.106.36
Mar 5 16:48:46.792: esmtp_client_work: socket 0 readable for first time
Mar 5 16:48:46.792: esmtp_client_work: socket 0 readable for first time
Mar 5 16:48:46.796: (C)R: 220 testlab-smtp.testlab-t37.com Microsoft ESMTP MAIL Service,
 Version: 5.0.2195.4453 ready at Tue, 5 Mar 2002 16:48:12 -0500 
!--- This is the SMTP server information displayed with the login.

Mar 5 16:48:46.796: (C)S: EHLO vdtl-5300-7a.testlab-t37.com
Mar 5 16:48:47.208: (C)R: 250-testlab-smtp.testlab-t37.com Hello [15.80.7.11]

!--- All the responses through the R: 250 OK are in response to the EHLO command from
!--- the sender (the 5300). These are the capabilities of the receiver.

Mar 5 16:48:47.208: (C)R: 250-TURN
Mar 5 16:48:47.208: (C)R: 250-ATRN 
Mar 5 16:48:47.208: (C)R: 250-SIZE
Mar 5 16:48:47.208: (C)R: 250-ETRN 
Mar 5 16:48:47.212: (C)R: 250-PIPELINING
Mar 5 16:48:47.212: (C)R: 250-DSN
Mar 5 16:48:47.212: (C)R: 250-ENHANCEDSTATUSCODES
Mar 5 16:48:47.212: (C)R: 250-8bitmime                                                          
Mar 5 16:48:47.212: (C)R: 250-BINARYMIME                                              
Mar 5 16:48:47.212: (C)R: 250-CHUNKING                                                             
Mar 5 16:48:47.212: (C)R: 250-VRFY                                                             
Mar 5 16:48:47.212: (C)R: 250-X-EXPS GSSAPI NTLM LOGIN                   
Mar 5 16:48:47.212: (C)R: 250-X-EXPS=LOGIN                                            
Mar 5 16:48:47.212: (C)R: 250-AUTH GSSAPI NTLM LOGIN                      
Mar 5 16:48:47.212: (C)R: 250-AUTH=LOGIN                                              
Mar 5 16:48:47.212: (C)R: 250-X-LINK2STATE                                           
Mar 5 16:48:47.212: (C)R: 250-XEXCH50                                                     
Mar 5 16:48:47.212: (C)R: 250 OK                                                                 
Mar 5 16:48:47.212: (C)S: MAIL FROM:<FAX=@>                                    
!--- This is the mail from command.

Mar 5 16:48:47.708: (C)R: 501 5.5.4 Invalid Address                                    
!--- The server does not like the address.

Mar 5 16:48:47.708: esmtp_client_work: error in response to MAIL FROM  
!--- This tells exactly where the problem ocurred in the SMTP exchange.

Mar 5 16:48:47.708: esmtp_client_work: ERROR, socket=0
Mar 5 16:49:15.132: %MSPI-4-MSPI_NO_SMTP_SEND: MSPI- Could not
send data to the SMTP server, cid=96, mspi_on_xmit, lost connection
Mar 5 16:49:15.132: %LAPP_ON_MSGS-6-LAPP_ON_CAUSE_NO_ESMTP_CONNECT: ESMTP client did not
 connect or lost connection to remote server
Mar 5 16:49:15.208: esmtp_client_work: Freeing ctx=0x62616C4C
Mar 5 16:49:15.208: esmtp_client: returned from work, context freed

No server configured

fax receive called-subscriber 8913180
fax interface-type fax-mail
mta send subject Fax from On-Ramp GW vdlt-5300-7a
mta send postmaster administrator@testlab-t37.com
mta send mail-from hostname vdtl-5300-7a.testlab-t37.com
mta send mail-from username $s$
mta receive maximum-recipients 0

vdtl-5300-7a#
Mar 4 10:46:48.703: mspi_setup_req: for cid=0x3F
Mar 4 10:46:48.703: %MSPI-1-MSPI_BAD_CONFIG: MSPI-bad configuration, mspi_setup_req:
 NULL server ip address
Mar 4 10:46:48.703: mspi_setup_req: NULL server address
Mar 4 10:46:48.703: %LAPP_ON_MSGS-6-LAPP_ON_CAUSE_NO_ESMTP_CONNECT: ESMTP client
 did not connect or lost connection to remote server
vdtl-5300-7a# 

Server configured but no IP route to server exists

vdtl-5300-7a# debug mspi send 
Mail SPI send debugging is on
vdtl-5300-7a#
Mar 20 09:35:27.126: %ISDN-6-CONNECT: Interface Serial0:18 is now connected to 8915510 
Mar 20 09:35:29.306: mspi_setup_req: for cid=0x141
Mar 20 09:35:29.306: envelope_from=FAX=8915510@vdtl-5300-7a.testlab-t37.com
Mar 20 09:35:29.310: envelope_to=FAX=8913144@testlab-t37.com
Mar 20 09:35:30.310: mspi_chk_connect: cid=0x141, cnt=0, 
Mar 20 09:35:30.310: SMTP is in the error state...
Mar 20 09:35:30.310: disc text=no route to destination (3): SMTP client open failed
Mar 20 09:35:30.310: Still waiting for the SMTP connection.....  
!--- You can tell that the SMTP connection was never established.

Mar 20 09:35:30.310: %LAPP_ON_MSGS-6-LAPP_ON_CAUSE_NO_ESMTP_CONNECT: ESMTP client
 did not connect or lost connection to remote server
Mar 20 09:35:30.310: mspi_disconnect: cid=0x141, st=DISCONNECTING, cause=no route
 to destination (3)  
!--- This cause code seems to be an accurate description of the problem.

Mar 20 09:35:30.310: mspi_on_call_hist: cid=0x141, cause=no route to destination (3):
 SMTP client open failed
Mar 20 09:35:30.310: disposing smtp ctx
Mar 20 09:35:30.310: mspi_free_ccb: mmccb allocated=1, inserted=0
Mar 20 09:35:36.006: %ISDN-6-DISCONNECT: Interface Serial0:18 disconnected from 8915510,
 call lasted 14 seconds
vdtl-5300-7a#

Note: The router is not sending a Fully Qualified Domain Name (FQDN) to the MS Exchange server and it doesn't like the syntax. This is because the router requires a reload after adding "ip domain-name domain "

vdtl-5300-7a# debug mmoip send email andy@testlab-t37.com
vdtl-5300-7a#
Mar 28 09:55:16.768: %SYS-5-CONFIG_I: Configured from console by console
Mar 28 09:55:17.936: esmtp_client_engine_open: from=testing@vdtl-5300-7a.testlab-t37.com,
 to=andy@testlab-t37.com
Mar 28 09:55:17.940: esmtp_client_engine_add_headers: from_comment=mspi Test User
Mar 28 09:55:18.072: esmtp_client_work: socket 0 attempting to connect to IP
 address 172.18.106.36
Mar 28 09:55:18.072: esmtp_client_work: socket 0 readable for first time
Mar 28 09:55:18.072: esmtp_client_work: socket 0 readable for first time
Mar 28 09:55:18.076: (C)R: 220 testlab-smtp.testlab-t37.com Microsoft ESMTP MAIL Service,
 Version: 5.0.2195.4453 ready at Thu, 28 Mar 2002 09:54:02 -0500 
Mar 28 09:55:18.076: (C)S: EHLO vdtl-5300-7a.  
!--- The Exchange server does not like the trailing dot (.).

Mar 28 09:55:18.484: (C)R: 501 5.5.4 Invalid Address
Mar 28 09:55:18.484: esmtp_client_work: EHLO failed; will try sending HELO
Mar 28 09:55:18.484: (C)S: HELO vdtl-5300-7a.
Mar 28 09:55:18.984: (C)R: 501 5.5.4 Invalid Address
Mar 28 09:55:18.984: esmtp_client_work: error in response to HELO
Mar 28 09:55:18.984: esmtp_client_work: ERROR, socket=0
Mar 28 09:55:18.984: esmtp_client_work: Freeing ctx=0x62661F18
Mar 28 09:55:18.988: esmtp_client: returned from work, context freed
vdtl-5300-7a#

Working Debugs

These debug commands are used for the SMTP side of OnRamp:

vdtl-5300-7a# debug foip on-ramp 
FOIP On ramp faxmail debugging is on
vdtl-5300-7a#
Mar 18 10:57:50.995: lapp_on_application: Incoming Event: (15 = CC_EV_CALL_HANDOFF),
 CID(216), DISP(0)
Mar 18 10:57:50.995: lapp_on_call_handoff: Authentication enabled = FALSE
Mar 18 10:57:50.995: lapp_on_call_handoff: Authentication ID = 0
Mar 18 10:57:50.995: lapp_on_call_handoff: Authentication ID source = IVR or unknown
Mar 18 10:57:50.999: lapp_on_call_handoff: Authentication status = SUCCESS
Mar 18 10:57:50.999: lapp_on_call_handoff: Accounting enabled = FALSE
Mar 18 10:57:50.999: lapp_on_call_handoff: Accounting method list = fax
Mar 18 10:57:50.999: lapp_on_call_handoff: Mailto Address = 
Mar 18 10:57:50.999: lapp_on_conference_vtsp_fmsp: Begin conferencing VTSP and FMSP... 
Mar 18 10:57:50.999: lapp_on_change_state: old state(0) new state(1) 
!--- HANDOFF to VTSP_FMSP_CONFERENCING

Mar 18 10:57:51.003: lapp_on_application: Incoming Event: (29 = CC_EV_CONF_CREATE_DONE),
 CID(216), DISP(0)
Mar 18 10:57:51.003: lapp_on_application: Current call state = 1 
Mar 18 10:57:51.003: lapp_on_conference_created: The VTSP and the FMSP are conferenced
Mar 18 10:57:51.003: lapp_on_conference_created: Wait for FMSP call detail event
Mar 18 10:57:51.003: lapp_on_change_state: old state(1) new state(2) 
!--- VTSP_FMSP_CONFERENCING to FMSP_CALL_DETAIL

Mar 18 10:57:57.075: %ISDN-6-CONNECT: Interface Serial0:18 is now connected to 8915510 
Mar 18 10:57:59.135: lapp_on_application: Incoming Event: (33 = CC_EV_FROM_FMSP_ON_CALL_DETAIL),
 CID(217), DISP(0)
Mar 18 10:57:59.139: lapp_on_application: Current call state = 2 
Mar 18 10:57:59.139: lapp_on_msp_event: Incoming call detail has arrived from the FMSP
Mar 18 10:57:59.139: lapp_on_setup_mspi: Prep MSPI ccCallSetupRequest... 
Mar 18 10:57:59.139: lapp_on_setup_mspi: Envelope from: FAX=8915510@vdtl-5300-7a.testlab-t37.com
Mar 18 10:57:59.139: lapp_on_setup_mspi: Envelope to: FAX=8913144@testlab-t37.com
Mar 18 10:57:59.139: lapp_on_setup_mspi: rfc822_to_comment: 8913144
Mar 18 10:57:59.139: lapp_on_setup_mspi: Faxmail subject: Fax from On-Ramp GW vdlt-5300-7a
[DNIS=8913144][ANI=8915510]
Mar 18 10:57:59.139: lapp_on_setup_mspi: Disposition notification to: admin@testlab-t37.com

!--- A read receipt is sent to admin@testlab-t37.com if the reader so chooses.

Mar 18 10:57:59.139: lapp_on_setup_mspi: Originator's TSI = rfc822_from_comment = Fax 
Mar 18 10:57:59.139: lapp_on_setup_mspi: Auth/Account ID = 0
Mar 18 10:57:59.139: lapp_on_setup_mspi: Do ccCallSetupRequest to MSPI
Mar 18 10:57:59.139: lapp_on_conference_fmsp_dmsp: Starting conference with FMSP and DMSP
Mar 18 10:57:59.139: lapp_on_conference_fmsp_dmsp: tiff file created = 2002:03:18 10:57:59
Mar 18 10:57:59.139: lapp_on_change_state: old state(2) new state(3)  
!--- FMSP_CALL_DETAIL to FMSP_DMSP_CONFERENCING

Mar 18 10:57:59.139: lapp_on_application: Incoming Event: (29 = CC_EV_CONF_CREATE_DONE),
 CID(217), DISP(0)
Mar 18 10:57:59.139: lapp_on_application: Current call state = 3 
Mar 18 10:57:59.139: lapp_on_conference_created: The FMSP and the DMSP are conferenced
Mar 18 10:57:59.139: lapp_on_conference_created: Sending
 CC_EV_TO_FMSP_ON_RECEIVE_ENABLE to FMSP
Mar 18 10:57:59.139: lapp_on_change_state: old state(3) new state(4)    
!--- FMSP_DMSP_CONFERENCING to FMSP_PAGE_ACCEPT_REQUESTED

Mar 18 10:58:00.139: lapp_on_application: Incoming Event: (8 = CC_EV_CALL_CONNECTED),
 CID(218), DISP(0)
Mar 18 10:58:00.139: lapp_on_application: Current call state = 4 
Mar 18 10:58:00.139: lapp_on_call_connected: Call connected event received.... - CID(218)
Mar 18 10:58:00.139: lapp_on_call_connected: MSPI call connected - CID(218)
Mar 18 10:58:00.139: lapp_on_call_connected: Start conferencing the DMSP and the MSPI
Mar 18 10:58:00.139: lapp_on_application: Incoming Event: (29 = CC_EV_CONF_CREATE_DONE),
 CID(219), DISP(0)
Mar 18 10:58:00.139: lapp_on_application: Current call state = 4 
Mar 18 10:58:11.539: lapp_on_application: Incoming Event:
 (36 = CC_EV_FROM_FMSP_ON_PAGE_ACCEPT_REQUESTED), CID(217), DISP(0)
Mar 18 10:58:11.539: lapp_on_application: Current call state = 4 
Mar 18 10:58:11.539: lapp_on_msp_event: Page accept request arrived from fmsp
Mar 18 10:58:11.539: lapp_on_msp_event: Sending page accept event to the FMSP
Mar 18 10:58:11.539: lapp_on_msp_event: Pages processed = 1

!--- The first fax page is received.

Mar 18 10:58:11.539: lapp_on_change_state: old state(4) new state(4)
Mar 18 10:58:16.015: lapp_on_application: Incoming Event:
 (37 = CC_EV_FROM_DMSP_ON_PAGE_PROCESSED), CID(219), DISP(146)
Mar 18 10:58:16.015: lapp_on_application: Current call state = 4 
Mar 18 10:58:16.015: lapp_on_msp_event: Page processed event arrived from the DMSP
Mar 18 10:58:16.015: lapp_on_change_state: old state(4) new state(4)
Mar 18 10:58:30.719: lapp_on_application: Incoming Event:
 (36 = CC_EV_FROM_FMSP_ON_PAGE_ACCEPT_REQUESTED), CID(217), DISP(0)
Mar 18 10:58:30.719: lapp_on_application: Current call state = 4 
Mar 18 10:58:30.719: lapp_on_msp_event: Page accept request arrived from fmsp
Mar 18 10:58:30.719: lapp_on_msp_event: Sending page accept event to the FMSP
Mar 18 10:58:30.719: lapp_on_msp_event: Pages processed = 2

!--- The second fax page is received.

Mar 18 10:58:30.719: lapp_on_change_state: old state(4) new state(4)
Mar 18 10:58:32.199: lapp_on_application: Incoming Event:
 (37 = CC_EV_FROM_DMSP_ON_PAGE_PROCESSED), CID(219), DISP(0)
Mar 18 10:58:32.199: lapp_on_application: Current call state = 4 
Mar 18 10:58:32.199: lapp_on_msp_event: Page processed event arrived from the DMSP
Mar 18 10:58:32.199: lapp_on_change_state: old state(4) new state(4)
Mar 18 10:58:34.355: lapp_on_application: Incoming Event: (11 = CC_EV_CALL_DISCONNECTED),
 CID(218), DISP(0)
Mar 18 10:58:34.355: lapp_on_application: Current call state = 4 
Mar 18 10:58:34.355: lapp_on_call_disconnected: Call Disconnected - CID= 218 cause=
 0x10 call_state= 4
Mar 18 10:58:34.355: lapp_on_call_disconnected: MSPI disconnected
Mar 18 10:58:34.355: lapp_on_call_disconnected: Faxmail acknowledged by remote SMTP server
Mar 18 10:58:34.355: lapp_on_change_state: old state(4) new state(7)  
!--- FMSP_PAGE_ACCEPT_REQUESTED to CONFERENCE_DESTROYING

Mar 18 10:58:34.355: lapp_on_conference_cleanup: Destroying conferences... 
Mar 18 10:58:34.355: lapp_on_conference_cleanup: Destroying conference for VTSP & FMSP
Mar 18 10:58:34.355: lapp_on_conference_cleanup: Destroying conference for FMSP & DMSP
Mar 18 10:58:34.355: lapp_on_conference_cleanup: Destroying conference for DMSP & MSPI
Mar 18 10:58:34.355: lapp_on_application: Incoming Event: (30 = CC_EV_CONF_DESTROY_DONE),
 CID(217), DISP(0)
Mar 18 10:58:34.355: lapp_on_application: Current call state = 7 
Mar 18 10:58:34.355: lapp_on_conference_destroyed: FMSP/DMSP conference destroyed
Mar 18 10:58:34.355: lapp_on_conference_destroyed: Conference destroyed..... confID = 150
Mar 18 10:58:34.355: lapp_on_application: Incoming Event: (30 = CC_EV_CONF_DESTROY_DONE),
 CID(219), DISP(0)
Mar 18 10:58:34.355: lapp_on_application: Current call state = 7 
Mar 18 10:58:34.355: lapp_on_conference_destroyed: DMSP/MSPI conference destroyed
Mar 18 10:58:34.355: lapp_on_conference_destroyed: Conference destroyed..... confID = 151
Mar 18 10:58:34.355: lapp_on_application: Incoming Event: (30 = CC_EV_CONF_DESTROY_DONE),
 CID(216), DISP(0)
Mar 18 10:58:34.355: lapp_on_application: Current call state = 7 
Mar 18 10:58:34.355: lapp_on_conference_destroyed: VTSP/FMSP conference destroyed
Mar 18 10:58:34.355: lapp_on_conference_destroyed: Conference destroyed..... confID = 149
Mar 18 10:58:34.355: lapp_on_change_state: old state(7) new state(8)  
!--- CONFERENCE_DESTROYING to DISCONNECTING

Mar 18 10:58:34.355: lapp_on_conference_destroyed: All conferences are destroyed. 
Mar 18 10:58:34.355: lapp_on_change_state: old state(8) new state(8)
Mar 18 10:58:34.355: lapp_on_call_leg_cleanup: Sending disconnect for FMSP
Mar 18 10:58:34.359: lapp_on_call_leg_cleanup: Sending disconnect for DMSP
Mar 18 10:58:34.359: lapp_on_application: Incoming Event:
 (12 = CC_EV_CALL_DISCONNECT_DONE), CID(219), DISP(0)
Mar 18 10:58:34.359: lapp_on_application: Current call state = 8 
Mar 18 10:58:34.359: lapp_on_disconnect_done: Received call disconnect done ... callID = 219
Mar 18 10:58:34.359: lapp_on_disconnect_done: DMSP disconnect done
Mar 18 10:58:34.359: lapp_on_disconnect_done: Sending disconnect for MSPI
Mar 18 10:58:34.359: lapp_on_application: Incoming Event:
 (12 = CC_EV_CALL_DISCONNECT_DONE), CID(218), DISP(0)
Mar 18 10:58:34.359: lapp_on_application: Current call state = 8 
Mar 18 10:58:34.359: lapp_on_disconnect_done: Received call disconnect done ... callID = 218
Mar 18 10:58:34.359: lapp_on_disconnect_done: MSPI disconnect done
Mar 18 10:58:34.363: lapp_on_application: Incoming Event:
 (12 = CC_EV_CALL_DISCONNECT_DONE), CID(217), DISP(0)
Mar 18 10:58:34.363: lapp_on_application: Current call state = 8 
Mar 18 10:58:34.363: lapp_on_disconnect_done: Received call disconnect done ... callID = 217
Mar 18 10:58:34.363: lapp_on_disconnect_done: FMSP disconnect done
Mar 18 10:58:34.363: lapp_on_disconnect_done: Sending disconnect for VTSP
Mar 18 10:58:36.627: %ISDN-6-DISCONNECT: Interface Serial0:18 disconnected from 8915510 ,
 call lasted 45 seconds
Mar 18 10:58:37.647: lapp_on_application: Incoming Event: (28 = CC_EV_CALL_FEATURE),
 CID(216), DISP(0)
Mar 18 10:58:37.647: lapp_on_application: Current call state = 8 
Mar 18 10:58:37.647: lapp_on_event_unsupported: Unsupported event received--- 
Mar 18 10:58:37.647: lapp_on_event_unsupported: EV(28=CC_EV_CALL_FEATURE),
 CID(216), disp(0)
Mar 18 10:58:37.647: lapp_on_event_unsupported: Current call state = 8 
Mar 18 10:58:37.651: lapp_on_application: Incoming Event:
 (12 = CC_EV_CALL_DISCONNECT_DONE), CID(216), DISP(0)
Mar 18 10:58:37.651: lapp_on_application: Current call state = 8 
Mar 18 10:58:37.651: lapp_on_disconnect_done: Received call disconnect done ... callID = 216
Mar 18 10:58:37.651: lapp_on_disconnect_done: VTSP disconnect done
Mar 18 10:58:37.651: lapp_on_disconnect_done: All the calls are now void or disconnected
Mar 18 10:58:37.651: lapp_on_change_state: old state(8) new state(9)
!---  DISCONNECTING to TERMINAL

Mar 18 10:58:37.651: lapp_on_call_terminate: Freeing the IVR call handoff record
Mar 18 10:58:37.655: lapp_on_call_terminate: Freeing the fax call record
vdtl-5300-7a#

onramp_faxing2.gif

The client receiving the email sees a window similar to the one above when opening an email with an MDN set. The response that the requestor receives is in the form of email sent to the user with message text that reads, "This is a receipt for the email you sent to "8913144" <Fax=8913144@testlab-t37.com> at 3/18/2002 10:58AM. This receipt verifies that the message has been displayed on the recipient's computer at 3/18/2002 11:07 AM."

vdtl-5300-7a# debug mta send all 
All email send debugging is on
vdtl-5300-7a#
Mar 18 14:50:46.278: %ISDN-6-CONNECT: Interface Serial0:18 is now connected to 8915510 
Mar 18 14:50:48.474: esmtp_client_engine_open:
 from=FAX=8915510@vdtl-5300-7a.testlab-t37.com, to=FAX=8913144@testlab-t37.com
Mar 18 14:50:48.474: esmtp_client_engine_add_headers: from_comment=Fax 
Mar 18 14:50:48.702: esmtp_client_work: socket 0 attempting to connect to
 IP address 172.18.106.36
Mar 18 14:50:48.702: esmtp_client_work: socket 0 readable for first time
Mar 18 14:50:48.702: esmtp_client_work: socket 0 readable for first time
Mar 18 14:50:48.706: (C)R: 220 testlab-smtp.testlab-t37.com Microsoft ESMTP MAIL Service,
 Version: 5.0.2195.4453 ready at Mon, 18 Mar 2002 14:49:51 -0500 
Mar 18 14:50:48.706: (C)S: EHLO vdtl-5300-7a.testlab-t37.com
Mar 18 14:50:49.166: (C)R: 250-testlab-smtp.testlab-t37.com Hello [15.80.7.11]
Mar 18 14:50:49.166: (C)R: 250-TURN
Mar 18 14:50:49.170: (C)R: 250-ATRN
Mar 18 14:50:49.170: (C)R: 250-SIZE
Mar 18 14:50:49.170: (C)R: 250-ETRN
Mar 18 14:50:49.170: (C)R: 250-PIPELINING
Mar 18 14:50:49.170: (C)R: 250-DSN
Mar 18 14:50:49.170: (C)R: 250-ENHANCEDSTATUSCODES
Mar 18 14:50:49.170: (C)R: 250-8bitmime
Mar 18 14:50:49.170: (C)R: 250-BINARYMIME
Mar 18 14:50:49.170: (C)R: 250-CHUNKING
Mar 18 14:50:49.170: (C)R: 250-VRFY
Mar 18 14:50:49.170: (C)R: 250-X-EXPS GSSAPI NTLM LOGIN
Mar 18 14:50:49.170: (C)R: 250-X-EXPS=LOGIN
Mar 18 14:50:49.170: (C)R: 250-AUTH GSSAPI NTLM LOGIN
Mar 18 14:50:49.170: (C)R: 250-AUTH=LOGIN
Mar 18 14:50:49.170: (C)R: 250-X-LINK2STATE
Mar 18 14:50:49.170: (C)R: 250-XEXCH50
Mar 18 14:50:49.170: (C)R: 250 OK
Mar 18 14:50:49.170: (C)S: MAIL FROM:<FAX=8915510@vdtl-5300-7a.testlab-t37.com> RET=HDRS
Mar 18 14:50:49.666: (C)R: 250 2.1.0 FAX=8915510@vdtl-5300-7a.testlab-t37.com....Sender OK
Mar 18 14:50:49.666: (C)S: RCPT TO:<FAX=8913144@testlab-t37.com> NOTIFY=SUCCESS,FAILURE
 ORCPT=rfc822;FAX+3D8915510@vdtl-5300-7a.testlab-t37.com
Mar 18 14:50:50.170: (C)R: 250 2.1.5 FAX=8913144@testlab-t37.com 
Mar 18 14:50:50.698: (C)R: 354 Start mail input; end with <CRLF>.<CRLF>
Mar 18 14:50:50.698: (C)S: Received: by vdtl-5300-7a.testlab-t37.com for
 <FAX=8913144@testlab-t37.com> (with Cisco NetWorks); Mon, 18 Mar 2002 14:50:50 -0500
Mar 18 14:50:50.698: (C)S: To: "8913144" <FAX=8913144@testlab-t37.com>
Mar 18 14:50:50.698: (C)S: Message-ID: <008C2002145050698@vdtl-5300-7a.testlab-t37.com>
Mar 18 14:50:50.702: (C)S: Date: Mon, 18 Mar 2002 14:50:50 -0500
Mar 18 14:50:50.702: (C)S: Subject: Fax from On-Ramp GW vdlt-5300-7a[DNIS=8913144]
 [ANI=8915510]
Mar 18 14:50:50.702: (C)S: X-Mailer: IOS (tm) 5300 Software (C5300-IS-M)
Mar 18 14:50:50.702: (C)S: Disposition-Notification-To: admin@testlab-t37.com
Mar 18 14:50:50.702: (C)S: MIME-Version: 1.0
Mar 18 14:50:50.702: (C)S: Content-Type: multipart/fax-message;
Mar 18 14:50:50.702: (C)S: boundary="yradnuoB=_008B2002145048474.vdtl-5300-7atestlab-t37.com"
Mar 18 14:50:50.702: (C)S: From: "Fax " <FAX=8915510@vdtl-5300-7a.testlab-t37.com>
Mar 18 14:50:50.702: (C)S: X-Account-Id: 0
Mar 18 14:51:05.702: (C)S: --yradnuoB=_008B2002145048474.vdtl-5300-7atestlab-t37.com
Mar 18 14:51:05.702: (C)S: Content-ID: <008D2002145105702@vdtl-5300-7a.testlab-t37.com>
Mar 18 14:51:05.702: (C)S: Content-Type: image/tiff; application=faxbw
Mar 18 14:51:05.702: (C)S: Content-Transfer-Encoding: base64
Mar 18 14:51:05.706: esmtp_client_work: writing lingering data for socket 0
Mar 18 14:51:05.714: esmtp_client_work: writing lingering data for socket 0
Mar 18 14:51:14.726: esmtp_client_work: writing lingering data for socket 0
Mar 18 14:51:14.734: esmtp_client_work: writing lingering data for socket 0
Mar 18 14:51:14.738: (C)S: --yradnuoB=_008B2002145048474.vdtl-5300-7atestlab-t37.com--
Mar 18 14:51:14.738: esmtp_client_work: Sending terminating dot ...(socket=0)
Mar 18 14:51:14.738: (C)S: .  
!--- This is the terminating dot to end the SMTP session.

Mar 18 14:51:14.986: (C)R: 250 2.6.0 <008C2002145050698@vdtl-5300-7a.testlab-t37.com>
 Queued mail for delivery
Mar 18 14:51:14.986: (C)S: QUIT
Mar 18 14:51:15.406: (C)R: 221 2.0.0 testlab-smtp.testlab-t37.com Service closing
 transmission channel
Mar 18 14:51:15.406: esmtp_client_work: Freeing ctx=0x6266946C
Mar 18 14:51:15.406: esmtp_client: returned from work, context freed
Mar 18 14:51:18.938: %ISDN-6-DISCONNECT: Interface Serial0:18 disconnected from 8915510 ,
 call lasted 38 seconds
vdtl-5300-7a#
vdtl-5300-7a# debug dmsp fax-to-doc 
Doc MSP fax to doc debugging is on
vdtl-5300-7a#
Mar 18 14:53:03.338: %ISDN-6-CONNECT: Interface Serial0:18 is now connected to 8915510 
Mar 18 14:53:05.530: docmsp_call_setup_request: callid=227 
Mar 18 14:53:05.530: docmsp_call_setup_request(): ramp data dir=ONRAMP, conf dir=DEST
Mar 18 14:53:05.534: docmsp_caps_ind: call id=227, src=225
Mar 18 14:53:05.534: docmsp_bridge cfid=156, srccid=227, dstcid=225

Mar 18 14:53:05.534: docmsp_bridge(): ramp data dir=ONRAMP, conf dir=DEST, encode out=2
Mar 18 14:53:06.530: docmsp_bridge cfid=157, srccid=227, dstcid=226

Mar 18 14:53:06.530: docmsp_bridge(): ramp data dir=ONRAMP, conf dir=SRC, encode out=2
Mar 18 14:53:11.510: docmsp_xmit: call id src=225, dst=227
Mar 18 14:53:11.510: docmsp_process_rcv_data: call id src=225, dst=227 
Mar 18 14:53:12.350: docmsp_xmit: call id src=225, dst=227

!--- Output suppressed.

Mar 18 14:53:22.242: docmsp_process_rcv_data: call id src=225, dst=227 
Mar 18 14:53:22.242: docmsp_get_msp_event_buffer: 
Mar 18 14:53:23.082: docmsp_xmit: call id src=225, dst=227
Mar 18 14:53:23.082: docmsp_process_rcv_data: call id src=225, dst=227 
Mar 18 14:53:23.922: docmsp_xmit: call id src=225, dst=227

!--- Output suppressed.

Mar 18 14:53:36.950: docmsp_process_rcv_data: call id src=225, dst=227 
Mar 18 14:53:38.430: docmsp_xmit: call id src=225, dst=227
Mar 18 14:53:38.430: docmsp_process_rcv_data: call id src=225, dst=227 
Mar 18 14:53:38.434: docmsp_get_msp_event_buffer: 
Mar 18 14:53:41.022: docmsp_bdrop cfid=156, srccid=227, dstcid=225

Mar 18 14:53:41.022: docmsp_bdrop cfid=157, srccid=227, dstcid=226

Mar 18 14:53:41.026: docmsp_call_disconnect: callid=227 
Mar 18 14:53:41.026: docmsp_do_call_history: call id=227 
Mar 18 14:53:42.886: %ISDN-6-DISCONNECT: Interface Serial0:18 disconnected from 8915510 ,
 call lasted 45 seconds
vdtl-5300-7a#

Note: The debug mmoip send email address command does not display anything to the screen itself, but it is very useful. It uses the router as an SMTP client to send an email to the address given in the debug command. The email has the subject defined in the configuration and is from "mspi Test User". It contains a text attachment with the line, "This is a test email message sent via Cisco Powered Libretto Faxmail."

These are debugs for the fax side of OnRamp:

vdtl-5300-7a# debug fmsp send t30
FMSP send t30 debugging is on
vdtl-5300-7a#
Mar 19 14:50:04.604: t30 call4Leg=311, state=1, substate=4
Mar 19 14:50:04.604: received flag of modulation:
0 
Mar 19 14:50:04.628: %ISDN-6-CONNECT: Interface Serial0:18 is now connected to 8915510 
Mar 19 14:50:06.252: msg dump:FF C0 C2 4 4 4 4 4 4 4 4 4 4 4 4 4 4 4 4 4 1E 86 62 
Mar 19 14:50:06.252: 
Mar 19 14:50:06.252: t30 call4Leg=311, state=1, substate=4
Mar 19 14:50:06.252: received: TSI remote id string: Fax 

Mar 19 14:50:06.672: msg dump:FF C8 C1 0 47 E 
Mar 19 14:50:06.672: 
Mar 19 14:50:06.824: t30 call4Leg=311, state=1, substate=4
Mar 19 14:50:06.824: in response receive WAIT FOR CD
Mar 19 14:50:11.632: t30 call4Leg=311, state=1, substate=6
Mar 19 14:50:11.632: received flag of modulation:
8 
Mar 19 14:50:19.304: t30 call4Leg=311, state=1, substate=6
Mar 19 14:50:19.304: received flag of modulation:
0 
Mar 19 14:50:20.364: msg dump:FF C8 F2 
Mar 19 14:50:20.364: 
Mar 19 14:50:22.324: t30 call4Leg=311, state=1, substate=6
Mar 19 14:50:22.324: received flag of modulation:
8 
Mar 19 14:50:31.643: t30 call4Leg=311, state=1, substate=6
Mar 19 14:50:31.643: received flag of modulation:
0 
Mar 19 14:50:32.683: msg dump:FF C8 F4 
Mar 19 14:50:32.683: 
Mar 19 14:50:33.155: t30 call4Leg=311, state=0, substate=6
Mar 19 14:50:33.155: fax session aborted by aplication
Mar 19 14:50:37.295: %ISDN-6-DISCONNECT: Interface Serial0:18 disconnected from 8915510 ,
 call lasted 38 seconds
vdtl-5300-7a#
vdtl-5300-7a#debug fmsp receive t30 
FMSP receive t30 debugging is on
vdtl-5300-7a#
Mar 19 14:46:26.536: t30 call4Leg=307, state=1, substate=3  
!--- state=PHASE_B_RECEIVE  substate=TX_DIS_DTC_BLOCK

Mar 19 14:46:26.536: CSI_PACKET(8913180) 
!--- The CSI option, which shows that the called number is 8913180, is
!--- controlled by the fax receive called-subscriber configuration.

Mar 19 14:46:26.536: t30 call4Leg=307, state=1, substate=3
Mar 19 14:46:26.536: DIS_PACKET(speed: 5, resolution: 1, encoding:
1 
Mar 19 14:46:26.536: t30 call4Leg=307, state=1, substate=4   
!--- Moved to substate RX_DCS_DTC_BLOCK.

Mar 19 14:46:26.536: fax2_response_receive: PROCESSING
Mar 19 14:46:29.452: t30 call4Leg=307, state=1, substate=4
Mar 19 14:46:29.452: fax2_response_receive: PROCESSING
Mar 19 14:46:29.476: %ISDN-6-CONNECT: Interface Serial0:18 is now connected to 8915510 
Mar 19 14:46:30.736: t30 call4Leg=307, state=1, substate=3
Mar 19 14:46:30.736: CSI_PACKET(8913180) 
Mar 19 14:46:30.736: t30 call4Leg=307, state=1, substate=3
Mar 19 14:46:30.736: DIS_PACKET(speed: 5, resolution: 1, encoding:
1   
!--- speed=14400, resolution=, encoding=modified read

Mar 19 14:46:30.736: t30 call4Leg=307, state=1, substate=4
Mar 19 14:46:30.736: fax2_response_receive: PROCESSING
Mar 19 14:46:31.100: t30 call4Leg=307, state=1, substate=4
Mar 19 14:46:31.100: fax2_response_receive: PROCESSING
Mar 19 14:46:31.100: msg dump:FF C0 C2 4 4 4 4 4 4 4 4 4 4 4 4 4 4 4 4 4 1E 86 62 
Mar 19 14:46:31.100: 
Mar 19 14:46:31.100: t30 call4Leg=307, state=1, substate=4
Mar 19 14:46:31.100: received: TSI remote id string: Fax 

Mar 19 14:46:31.100: t30 call4Leg=307, state=1, substate=4
Mar 19 14:46:31.100: fax2_response_receive: PROCESSING
Mar 19 14:46:31.532: t30 call4Leg=307, state=1, substate=4
Mar 19 14:46:31.532: fax2_response_receive: PROCESSING
Mar 19 14:46:31.532: msg dump:FF C8 C1 0 47 E 
Mar 19 14:46:31.532: 
Mar 19 14:46:31.532: t30 call4Leg=307, state=1, substate=4
Mar 19 14:46:31.532: fax2_response_receive: PROCESSING
Mar 19 14:46:31.672: t30 call4Leg=307, state=1, substate=4
Mar 19 14:46:31.672: in response receive WAIT FOR CD
Mar 19 14:46:31.672: t30 call4Leg=307, state=1, substate=9   
!--- The substate is changed to RX_TCF.

Mar 19 14:46:31.672: received DCS_PACKET, BR: 9,  
!--- BR=v.21 14400

resolution: 1, encoding: 1, remote_id_string: Fax          
Mar 19 14:46:31.672: t30 call4Leg=307, state=1, substate=10  
!--- The substate is changed to WAIT_FOR_FDR.

Mar 19 14:46:31.672: wait for ready for data from
application
Mar 19 14:46:31.672: t30 call4Leg=307, state=1, substate=12   
!--- The substate is changed to TX_TCF_RESPONSE.

Mar 19 14:46:31.672: send CFR_PACKET
Mar 19 14:46:31.672: t30 call4Leg=307, state=1, substate=6   
!--- The substate is changed to CONFIGURE_RX_DATA.

Mar 19 14:46:31.672: fax2_configure_rx_data: STILL_LOOKING,
T2 timer not expired
Mar 19 14:46:36.472: t30 call4Leg=307, state=1, substate=6
Mar 19 14:46:36.472: fax2_configure_rx_data:
DETECTED_DATA
Mar 19 14:46:36.472: t30 call4Leg=307, state=2, substate=43  
!--- state = PHASE_C_RECEIVE, substate=RX_FIRST_DATA_BYTE - starting to RX page data...

Mar 19 14:46:36.472: No data yet
Mar 19 14:46:43.872: t30 call4Leg=307, state=2, substate=14  
!--- The substate is changed to RX_DATA.

Mar 19 14:46:43.872: end of page
Mar 19 14:46:43.872: t30 call4Leg=307, state=1, substate=6  
!--- The substate is changed to CONFIGURE_RX_DATA.

Mar 19 14:46:43.872: fax2_configure_rx_data: STILL_LOOKING,
T2 timer not expired
Mar 19 14:46:43.872: t30 call4Leg=307, state=1, substate=6
Mar 19 14:46:43.872: fax2_configure_rx_data: STILL_LOOKING,
T2 timer not expired
Mar 19 14:46:44.140: t30 call4Leg=307, state=1, substate=6
Mar 19 14:46:44.140: fax2_configure_rx_data:
DETECTED_COMMAND
Mar 19 14:46:44.140: t30 call4Leg=307, state=1, substate=7  
!--- The substate is changed to RX_COMMAND.

Mar 19 14:46:44.140: fax2_command_receive: NO_COMMAND, T2
timer not expired
Mar 19 14:46:45.200: t30 call4Leg=307, state=1, substate=7
Mar 19 14:46:45.200: fax2_command_receive: PROCESSING
Mar 19 14:46:45.200: msg dump:FF C8 F2 
Mar 19 14:46:45.200: 
Mar 19 14:46:45.200: t30 call4Leg=307, state=1, substate=7
Mar 19 14:46:45.200: fax2_command_receive: PROCESSING
Mar 19 14:46:45.352: t30 call4Leg=307, state=1, substate=7
Mar 19 14:46:45.352: fax2_command_receive:
RECEIVED_COMMAND
Mar 19 14:46:45.352: t30 call4Leg=307, state=3, substate=8    
!--- The substate is changed to ROUTE_COMMAND.

Mar 19 14:46:45.352: received MPS  
!--- Received Multipage Signal.

Mar 19 14:46:45.352: t30 call4Leg=307, state=3, substate=10  
!--- The substate is changed to WAIT_FOR_FDR.

Mar 19 14:46:45.352: waiting for page acceptence by the application
Mar 19 14:46:45.352: t30 call4Leg=307, state=3, substate=17  
!--- The substate is changed to SCHEDULE_PP_RESPONSE.

Mar 19 14:46:45.352: send MCF   
!--- Send a Message Confirmation.

Mar 19 14:46:45.352: t30 call4Leg=307, state=1, substate=6
Mar 19 14:46:45.352: fax2_configure_rx_data: STILL_LOOKING,
T2 timer not expired
Mar 19 14:46:47.172: t30 call4Leg=307, state=1, substate=6

!--- Now this must be done again, starting from the page data, because two pages
!--- are being sent.


Mar 19 14:46:47.172: fax2_configure_rx_data:
DETECTED_DATA
Mar 19 14:46:47.172: t30 call4Leg=307, state=2, substate=43
!--- state = PHASE_C_RECEIVE, substate=RX_FIRST_DATA_BYTE - starting to RX page data...

Mar 19 14:46:47.172: No data yet
Mar 19 14:46:56.212: t30 call4Leg=307, state=2, substate=14 
!--- The substate is changed to RX_DATA.

Mar 19 14:46:56.212: end of page
Mar 19 14:46:56.212: t30 call4Leg=307, state=1, substate=6
Mar 19 14:46:56.212: fax2_configure_rx_data: STILL_LOOKING,
T2 timer not expired
Mar 19 14:46:56.212: t30 call4Leg=307, state=1, substate=6
Mar 19 14:46:56.212: fax2_configure_rx_data: STILL_LOOKING,
T2 timer not expired
Mar 19 14:46:56.512: t30 call4Leg=307, state=1, substate=6
Mar 19 14:46:56.512: fax2_configure_rx_data:
DETECTED_COMMAND
Mar 19 14:46:56.512: t30 call4Leg=307, state=1, substate=7
Mar 19 14:46:56.512: fax2_command_receive: NO_COMMAND, T2
timer not expired
Mar 19 14:46:57.552: t30 call4Leg=307, state=1, substate=7
Mar 19 14:46:57.552: fax2_command_receive: PROCESSING
Mar 19 14:46:57.552: msg dump:FF C8 F4 
Mar 19 14:46:57.552: 
Mar 19 14:46:57.552: t30 call4Leg=307, state=1, substate=7
Mar 19 14:46:57.552: fax2_command_receive: PROCESSING
Mar 19 14:46:57.700: t30 call4Leg=307, state=1, substate=7
Mar 19 14:46:57.700: fax2_command_receive:
RECEIVED_COMMAND
Mar 19 14:46:57.700: t30 call4Leg=307, state=3, substate=8
Mar 19 14:46:57.700: received EOP   

!--- Received End of Procedure.

Mar 19 14:46:57.700: t30 call4Leg=307, state=3, substate=10
Mar 19 14:46:57.700: waiting for page acceptence by the application
Mar 19 14:46:57.700: t30 call4Leg=307, state=3, substate=17
Mar 19 14:46:57.700: send MCF       

!--- Send a Message Confirmation.

Mar 19 14:46:57.700: t30 call4Leg=307, state=1, substate=6
Mar 19 14:46:57.704: fax2_configure_rx_data: STILL_LOOKING,
T2 timer not expired
Mar 19 14:46:58.140: t30 call4Leg=307, state=0, substate=6  

!--- state=PHASE_IDLE

Mar 19 14:46:58.140: fax session aborted by aplication
Mar 19 14:47:02.188: %ISDN-6-DISCONNECT: Interface Serial0:18 disconnected from 8915510 ,
 call lasted 38 seconds
vdtl-5300-7a#
vdtl-5300-7a# debug fax relay t30 called-number 8913144
Debugging fax relay t30 to 8913144
vdtl-5300-7a#
Mar 19 14:40:19.134: 0:D:302 1205778176 fr-entered (10ms)
Mar 19 14:40:22.498: 0:D:302 1205781540 fr-msg-tx CSI
Mar 19 14:40:23.826: 0:D:302 1205782870 fr-msg-tx DIS
Mar 19 14:40:25.070: %ISDN-6-CONNECT: Interface Serial0:18 is now connected to 8915510 
Mar 19 14:40:26.146: 0:D:302 1205785190 fr-msg-det TSI
Mar 19 14:40:27.026: 0:D:302 1205786070 fr-msg-det DCS
Mar 19 14:40:30.558: 0:D:302 1205789600 fr-msg-tx CFR
Mar 19 14:40:40.766: 0:D:302 1205799810 fr-msg-det MPS
Mar 19 14:40:41.266: 0:D:302 1205800310 fr-msg-tx MCF
Mar 19 14:40:53.098: 0:D:302 1205812140 fr-msg-det EOP
Mar 19 14:40:53.598: 0:D:302 1205812640 fr-msg-tx MCF
Mar 19 14:40:56.390: 0:D:302 1205815430 fr-msg-det DCN
Mar 19 14:40:57.682: %ISDN-6-DISCONNECT: Interface Serial0:18 disconnected from 8915510 ,
 call lasted 38 seconds
Mar 19 14:40:58.518: 0:D:302 1205817560 fr-end-dcn

fr-msg-tx indicates T.30 messages that are transmitted by the router
fr-msg-det indicates T.30 messages that are received by the router

For more information, refer to the Fax Relay Troubleshooting Guide.

show Commands

vdtl-5300-7a# show call history fax brief 
<ID>: <start>hs.<index> +<connect> +<disc> pid:<peer_id> <direction> <addr>
dur hh:mm:ss tx:<packets>/<bytes> rx:<packets>/<bytes> <disc-cause>(<text>)
IP <ip>:<udp> rtt:<time>ms pl:<play>/<gap>ms lost:<lost>/<early>/<late>
delay:<last>/<min>/<max>ms <codec>
MODEMPASS <method> buf:<fills>/<drains> loss <overall%> <multipkt>/<corrected>
last <buf event time>s dur:<Min>/<Max>s
FR <protocol> [int dlci cid] vad:<y/n> dtmf:<y/n> seq:<y/n>
<codec> (payload size)
ATM <protocol> [int vpi/vci cid] vad:<y/n> dtmf:<y/n> seq:<y/n>
<codec> (payload size)
Telephony <int>: tx:<tot>/<voice>/<fax>ms <codec> noise:<lvl>dBm acom:<lvl>dBm
Proxy <ip>:<audio udp>,<video udp>,<tcp0>,<tcp1>,<tcp2>,<tcp3> endpt: <type>/<manf>
bw: <req>/<act> codec: <audio>/<video>
tx: <audio pkts>/<audio bytes>,<video pkts>/<video bytes>,<t120 pkts>/<t120 bytes>
rx: <audio pkts>/<audio bytes>,<video pkts>/<video bytes>,<t120 pkts>/<t120 bytes>


Telephony call-legs: 3
SIP call-legs: 0
H323 call-legs: 0
Total call-legs: 5
1225 : 374672hs.31 +2 +1367 pid:8913180 Answer 8915510
dur 00:00:13 tx:7/124 rx:104/693 10 :1F (normal call clearing (16):normal,
 unspecified (31): User abort)
Telephony 0:D:61: tx:0/0/0ms 14400 noise:0dBm acom:0dBm

122B : 401714hs.32 +100 +2966 pid:1 Originate andy@testlab-t37.com
dur 00:00:28 tx:50942/0 rx:0/0 10 :0 (normal call clearing (16):)
IP 172.18.106.36 AcceptedMime:0 DiscardedMime:0

1229 : 400917hs.33 +1 +4108 pid:8913180 Answer 8915510
dur 00:00:41 tx:11/164 rx:760/45251 10 :10 (normal call clearing (16):normal
 call clearing (16): Normal conn)
Telephony 0:D:64: tx:0/0/0ms 14400 noise:0dBm acom:0dBm

1230 : 439580hs.34 +100 +2971 pid:1 Originate andy@testlab-t37.com
dur 00:00:28 tx:50942/0 rx:0/0 10 :0 (normal call clearing (16):)
IP 172.18.106.36 AcceptedMime:0 DiscardedMime:0

122E : 438783hs.35 +1 +4109 pid:8913180 Answer 8915510
dur 00:00:41 tx:11/164 rx:761/45256 10 :10 (normal call clearing (16):normal
 call clearing (16): Normal conn)
Telephony 0:D:68: tx:0/0/0ms 14400 noise:0dBm acom:0dBm

Related Information

Updated: Feb 02, 2006
Document ID: 47763