[hylafax-users] Xircom CEM56(Class2) Call aborted, from +FK or <CAN> (code 2)

[Darren Nickerson <darren@dazza.org>]

Folks,

In the spirit of getting HylaFAX flying with more modems, I decided to tackle 
the Class2 fax capability of my laptop's Xircom CEM56 10/100 Ethernet, 56.6 
KBps modem combo card. The card claims Hayes compliance, but does not document 
its fax commands, so I based my current config upon the PPIs. Things go very 
well indeed until the end of the transmission,

Jun 08 12:13:46.24: [16528]: SEND send MPS (more pages, same document)
Jun 08 12:13:46.24: [16528]: <-- [9:AT+FET=0\r]
Jun 08 12:13:49.63: [16528]: --> [7:+FPTS:1]
Jun 08 12:13:49.63: [16528]: --> [2:OK]
Jun 08 12:13:49.63: [16528]: SEND recv MCF (message confirmation)
Jun 08 12:13:49.63: [16528]: SEND FAX (00000047): FROM darren@dazza.org TO 
+12152438335 (page 1 of 2 sent in 0:17)
Jun 08 12:13:49.63: [16528]: SEND FAX (00000047): FROM darren@dazza.org TO 
+12152438335 (docq/doc23.ps;31 sent in 0:17)
Jun 08 12:13:49.64: [16528]: SEND file "docq/doc24.ps;31"
Jun 08 12:13:49.64: [16528]: USE page width 1728 pixels in 215 mm
Jun 08 12:13:49.64: [16528]: USE unlimited page length 
Jun 08 12:13:49.64: [16528]: USE 7.7 line/mm
Jun 08 12:13:49.64: [16528]: USE 1-D MR
Jun 08 12:13:49.64: [16528]: <-- [7:AT+FDT\r]
Jun 08 12:13:49.82: [16528]: --> [7:CONNECT]
Jun 08 12:13:49.82: [16528]: SEND wait for XON
Jun 08 12:13:49.82: [16528]: --> [1:]
Jun 08 12:13:49.82: [16528]: SEND begin page
Jun 08 12:13:49.83: [16528]: <-- data [1027]
Jun 08 12:13:49.83: [16528]: <-- data [821]
Jun 08 12:13:49.83: [16528]: SENT 1845 bytes of data
Jun 08 12:13:49.83: [16528]: SEND 1D RTC
Jun 08 12:13:49.83: [16528]: <-- data [9]
Jun 08 12:13:49.83: [16528]: <-- data [2]
Jun 08 12:13:49.83: [16528]: SEND end page
Jun 08 12:13:50.70: [16528]: --> [2:OK]
Jun 08 12:13:50.70: [16528]: SEND send EOP (no more pages or documents)
Jun 08 12:13:50.70: [16528]: <-- [9:AT+FET=2\r]
Jun 08 12:13:54.08: [16528]: --> [7:+FPTS:1]
Jun 08 12:13:54.08: [16528]: SEND recv MCF (message confirmation)
Jun 08 12:13:54.08: [16528]: SEND FAX (00000047): FROM darren@dazza.org TO 
+12152438335 (page 2 of 2 sent in 0:05)
Jun 08 12:13:54.08: [16528]: SEND FAX (00000047): FROM darren@dazza.org TO 
+12152438335 (docq/doc24.ps;31 sent in 0:05)
Jun 08 12:13:54.09: [16528]: <-- [5:ATH0\r]
Jun 08 12:13:54.19: [16528]: --> [7:+FHNG:2]
Jun 08 12:13:54.19: [16528]: REMOTE HANGUP: Call aborted,  from +FK or <CAN> 
(code 2)
Jun 08 12:13:55.19: [16528]: --> [2:OK]
Jun 08 12:13:55.19: [16528]: MODEM set DTR OFF
Jun 08 12:13:55.19: [16528]: STATE CHANGE: SENDING -> MODEMWAIT (timeout 5)
Jun 08 12:13:55.19: [16528]: SESSION END


Looks like a big delay between 

Jun 08 12:13:50.70: [16528]: <-- [9:AT+FET=2\r]
Jun 08 12:13:54.08: [16528]: --> [7:+FPTS:1]

Does anyone with class2 specs have any insight into what's going on here? I've 
attached the entire session log FYI.

-Darren

Jun 08 12:12:57.66: [16528]: SESSION BEGIN 00000047 12152438335
Jun 08 12:12:57.66: [16528]: SEND FAX: JOB 12 DEST +12152438335 COMMID 00000047
Jun 08 12:12:57.66: [16528]: MODEM set DTR OFF
Jun 08 12:12:57.66: [16528]: DELAY 2600 ms
Jun 08 12:13:00.27: [16528]: MODEM set DTR ON
Jun 08 12:13:00.27: [16528]: MODEM set baud rate: 38400 baud, input flow RTS/CTS, output flow RTS/CTS
Jun 08 12:13:00.27: [16528]: MODEM flush i/o
Jun 08 12:13:00.27: [16528]: <-- [4:ATZ\r]
Jun 08 12:13:00.90: [16528]: --> [3:ATZ]
Jun 08 12:13:00.90: [16528]: --> [2:OK]
Jun 08 12:13:00.90: [16528]: <-- [15:ATE0V1Q0S0=0H0\r]
Jun 08 12:13:00.91: [16528]: --> [14:ATE0V1Q0S0=0H0]
Jun 08 12:13:00.91: [16528]: --> [2:OK]
Jun 08 12:13:00.91: [16528]: <-- [21:ATS8=2S7=60&K3&D3&C1\r]
Jun 08 12:13:00.92: [16528]: --> [2:OK]
Jun 08 12:13:00.92: [16528]: <-- [12:AT+FCLASS=2\r]
Jun 08 12:13:00.93: [16528]: --> [2:OK]
Jun 08 12:13:00.93: [16528]: <-- [10:AT+FTBC=0\r]
Jun 08 12:13:00.94: [16528]: --> [2:OK]
Jun 08 12:13:00.94: [16528]: <-- [10:AT+FBOR=0\r]
Jun 08 12:13:00.95: [16528]: --> [2:OK]
Jun 08 12:13:00.95: [16528]: <-- [13:AT+FPHCTO=30\r]
Jun 08 12:13:00.96: [16528]: --> [2:OK]
Jun 08 12:13:00.96: [16528]: <-- [10:AT+FBUG=0\r]
Jun 08 12:13:00.97: [16528]: --> [2:OK]
Jun 08 12:13:00.97: [16528]: <-- [24:AT+FDCC=1,5,0,2,0,0,0,0\r]
Jun 08 12:13:00.98: [16528]: --> [2:OK]
Jun 08 12:13:00.98: [16528]: <-- [7:ATL3M1\r]
Jun 08 12:13:00.99: [16528]: --> [2:OK]
Jun 08 12:13:00.99: [16528]: STATE CHANGE: RUNNING -> SENDING
Jun 08 12:13:00.99: [16528]: MODEM input buffering enabled
Jun 08 12:13:00.99: [16528]: <-- [12:AT+FCLASS=2\r]
Jun 08 12:13:01.10: [16528]: --> [2:OK]
Jun 08 12:13:01.10: [16528]: <-- [10:AT+FTBC=0\r]
Jun 08 12:13:01.21: [16528]: --> [2:OK]
Jun 08 12:13:01.21: [16528]: <-- [10:AT+FBOR=0\r]
Jun 08 12:13:01.32: [16528]: --> [2:OK]
Jun 08 12:13:01.32: [16528]: <-- [13:AT+FPHCTO=30\r]
Jun 08 12:13:01.43: [16528]: --> [2:OK]
Jun 08 12:13:01.43: [16528]: <-- [10:AT+FBUG=0\r]
Jun 08 12:13:01.54: [16528]: --> [2:OK]
Jun 08 12:13:01.54: [16528]: <-- [24:AT+FDCC=1,5,0,2,0,0,0,0\r]
Jun 08 12:13:01.65: [16528]: --> [2:OK]
Jun 08 12:13:01.65: [16528]: <-- [26:AT+FLID="PhiladelphiaTPC"\r]
Jun 08 12:13:01.77: [16528]: --> [2:OK]
Jun 08 12:13:01.77: [16528]: <-- [24:AT+FDIS=1,5,0,2,0,0,0,0\r]
Jun 08 12:13:01.88: [16528]: --> [2:OK]
Jun 08 12:13:01.91: [16528]: DIAL 2152438335
Jun 08 12:13:01.91: [16528]: <-- [17:ATX3DT2152438335\r]
Jun 08 12:13:32.29: [16528]: --> [5:+FCON]
Jun 08 12:13:32.68: [16528]: --> [21:+FDIS:1,5,0,2,0,0,0,0]
Jun 08 12:13:32.68: [16528]: --> [2:OK]
Jun 08 12:13:32.68: [16528]: REMOTE best rate 14400 bit/s
Jun 08 12:13:32.68: [16528]: REMOTE max page width 1728 pixels in 215 mm
Jun 08 12:13:32.68: [16528]: REMOTE max unlimited page length 
Jun 08 12:13:32.68: [16528]: REMOTE best vres 7.7 line/mm
Jun 08 12:13:32.68: [16528]: REMOTE best format 1-D MR
Jun 08 12:13:32.68: [16528]: REMOTE best 0 ms/scanline
Jun 08 12:13:32.68: [16528]: USE 14400 bit/s
Jun 08 12:13:32.68: [16528]: USE 0 ms/scanline
Jun 08 12:13:32.68: [16528]: SEND file "docq/doc23.ps;31"
Jun 08 12:13:32.69: [16528]: USE page width 1728 pixels in 215 mm
Jun 08 12:13:32.69: [16528]: USE unlimited page length 
Jun 08 12:13:32.69: [16528]: USE 7.7 line/mm
Jun 08 12:13:32.69: [16528]: USE 1-D MR
Jun 08 12:13:32.69: [16528]: <-- [7:AT+FDT\r]
Jun 08 12:13:39.41: [16528]: --> [21:+FDCS:1,5,0,2,0,0,0,0]
Jun 08 12:13:39.52: [16528]: --> [7:CONNECT]
Jun 08 12:13:39.52: [16528]: SEND wait for XON
Jun 08 12:13:39.52: [16528]: --> [1:]
Jun 08 12:13:39.52: [16528]: SEND begin page
Jun 08 12:13:39.56: [16528]: <-- data [1028]
Jun 08 12:13:39.57: [16528]: <-- data [1026]
Jun 08 12:13:39.57: [16528]: <-- data [1026]
Jun 08 12:13:39.57: [16528]: <-- data [1031]
Jun 08 12:13:39.57: [16528]: <-- data [1030]
Jun 08 12:13:39.64: [16528]: <-- data [1030]
Jun 08 12:13:39.64: [16528]: <-- data [1031]
Jun 08 12:13:39.89: [16528]: <-- data [1029]
Jun 08 12:13:40.37: [16528]: <-- data [1030]
Jun 08 12:13:41.01: [16528]: <-- data [1030]
Jun 08 12:13:41.48: [16528]: <-- data [1029]
Jun 08 12:13:42.12: [16528]: <-- data [1033]
Jun 08 12:13:42.66: [16528]: <-- data [79]
Jun 08 12:13:42.66: [16528]: SENT 12366 bytes of data
Jun 08 12:13:42.66: [16528]: SEND 1D RTC
Jun 08 12:13:42.67: [16528]: <-- data [9]
Jun 08 12:13:42.67: [16528]: <-- data [2]
Jun 08 12:13:42.67: [16528]: SEND end page
Jun 08 12:13:46.24: [16528]: --> [2:OK]
Jun 08 12:13:46.24: [16528]: SEND send MPS (more pages, same document)
Jun 08 12:13:46.24: [16528]: <-- [9:AT+FET=0\r]
Jun 08 12:13:49.63: [16528]: --> [7:+FPTS:1]
Jun 08 12:13:49.63: [16528]: --> [2:OK]
Jun 08 12:13:49.63: [16528]: SEND recv MCF (message confirmation)
Jun 08 12:13:49.63: [16528]: SEND FAX (00000047): FROM darren@dazza.org TO +12152438335 (page 1 of 2 sent in 0:17)
Jun 08 12:13:49.63: [16528]: SEND FAX (00000047): FROM darren@dazza.org TO +12152438335 (docq/doc23.ps;31 sent in 0:17)
Jun 08 12:13:49.64: [16528]: SEND file "docq/doc24.ps;31"
Jun 08 12:13:49.64: [16528]: USE page width 1728 pixels in 215 mm
Jun 08 12:13:49.64: [16528]: USE unlimited page length 
Jun 08 12:13:49.64: [16528]: USE 7.7 line/mm
Jun 08 12:13:49.64: [16528]: USE 1-D MR
Jun 08 12:13:49.64: [16528]: <-- [7:AT+FDT\r]
Jun 08 12:13:49.82: [16528]: --> [7:CONNECT]
Jun 08 12:13:49.82: [16528]: SEND wait for XON
Jun 08 12:13:49.82: [16528]: --> [1:]
Jun 08 12:13:49.82: [16528]: SEND begin page
Jun 08 12:13:49.83: [16528]: <-- data [1027]
Jun 08 12:13:49.83: [16528]: <-- data [821]
Jun 08 12:13:49.83: [16528]: SENT 1845 bytes of data
Jun 08 12:13:49.83: [16528]: SEND 1D RTC
Jun 08 12:13:49.83: [16528]: <-- data [9]
Jun 08 12:13:49.83: [16528]: <-- data [2]
Jun 08 12:13:49.83: [16528]: SEND end page
Jun 08 12:13:50.70: [16528]: --> [2:OK]
Jun 08 12:13:50.70: [16528]: SEND send EOP (no more pages or documents)
Jun 08 12:13:50.70: [16528]: <-- [9:AT+FET=2\r]
Jun 08 12:13:54.08: [16528]: --> [7:+FPTS:1]
Jun 08 12:13:54.08: [16528]: SEND recv MCF (message confirmation)
Jun 08 12:13:54.08: [16528]: SEND FAX (00000047): FROM darren@dazza.org TO +12152438335 (page 2 of 2 sent in 0:05)
Jun 08 12:13:54.08: [16528]: SEND FAX (00000047): FROM darren@dazza.org TO +12152438335 (docq/doc24.ps;31 sent in 0:05)
Jun 08 12:13:54.09: [16528]: <-- [5:ATH0\r]
Jun 08 12:13:54.19: [16528]: --> [7:+FHNG:2]
Jun 08 12:13:54.19: [16528]: REMOTE HANGUP: Call aborted,  from +FK or <CAN> (code 2)
Jun 08 12:13:55.19: [16528]: --> [2:OK]
Jun 08 12:13:55.19: [16528]: MODEM set DTR OFF
Jun 08 12:13:55.19: [16528]: STATE CHANGE: SENDING -> MODEMWAIT (timeout 5)
Jun 08 12:13:55.19: [16528]: SESSION END