HylaFAX The world's most advanced open source fax server

[Date Prev][Date Next][Thread Prev][Thread Next] [Date Index] [Thread Index]

[hylafax-users] Log file interpretation



Sorry for the lengthy post.

Where is the log file produced by session tracing documented?
Specifically, I'm trying to debug a situation where a client
claims he's not getting a FAX, however the log file looks like the one 
included below.

I'm wondering what portion of this log file actually indicates that the
FAX machine at the remote end has acknowledged the reception of a given page.

For example: this snippet from below seems to indicate a successful page sent
but what do some of these entries mean.

Oct 02 20:14:31.94: [ 7351]: <-- data [2]
Oct 02 20:14:31.94: [ 7351]: SEND end page
Oct 02 20:14:35.52: [ 7351]: --> [136:]      <-- This means what?
Oct 02 20:14:35.52: [ 7351]: --> [2:OK]      <-- This means what?
Oct 02 20:14:35.52: [ 7351]: SEND send MPS (more pages, same document)


(The session log below has been modified to remove the FAX number dialed.)

Any enlightenment would be appreciated.

Regards,

Jeff H.

Oct 02 20:13:01.53: [ 7351]: SESSION BEGIN 00018197 1603xxxxxxx
Oct 02 20:13:01.53: [ 7351]: SEND FAX: JOB 10699 DEST xxxxxxx COMMID 00018197
Oct 02 20:13:01.53: [ 7351]: MODEM set DTR OFF
Oct 02 20:13:01.53: [ 7351]: DELAY 2600 ms
Oct 02 20:13:04.13: [ 7351]: MODEM set DTR ON
Oct 02 20:13:04.13: [ 7351]: MODEM set baud rate: 38400 baud, input flow 
RTS/CTS, output flow RTS/CTS
Oct 02 20:13:04.13: [ 7351]: MODEM flush i/o
Oct 02 20:13:04.13: [ 7351]: <-- [4:ATZ\r]
Oct 02 20:13:04.54: [ 7351]: --> [3:ATZ]
Oct 02 20:13:04.54: [ 7351]: --> [2:OK]
Oct 02 20:13:04.54: [ 7351]: <-- [15:ATE0V1Q0S0=0H0\r]
Oct 02 20:13:04.70: [ 7351]: --> [14:ATE0V1Q0S0=0H0]
Oct 02 20:13:04.70: [ 7351]: --> [2:OK]
Oct 02 20:13:04.70: [ 7351]: <-- [21:ATS8=2S7=60&E4&D3&C1\r]
Oct 02 20:13:04.90: [ 7351]: --> [2:OK]
Oct 02 20:13:04.90: [ 7351]: <-- [12:AT+FCLASS=2\r]
Oct 02 20:13:05.06: [ 7351]: --> [2:OK]
Oct 02 20:13:05.06: [ 7351]: <-- [10:AT+FTBC=0\r]
Oct 02 20:13:05.22: [ 7351]: --> [2:OK]
Oct 02 20:13:05.22: [ 7351]: <-- [10:AT+FBOR=0\r]
Oct 02 20:13:05.38: [ 7351]: --> [2:OK]
Oct 02 20:13:05.38: [ 7351]: <-- [13:AT+FPHCTO=30\r]
Oct 02 20:13:05.54: [ 7351]: --> [2:OK]
Oct 02 20:13:05.54: [ 7351]: <-- [10:AT+FBUG=1\r]
Oct 02 20:13:05.70: [ 7351]: --> [2:OK]
Oct 02 20:13:05.70: [ 7351]: <-- [24:AT+FDCC=1,5,2,2,2,0,0,0\r]
Oct 02 20:13:05.90: [ 7351]: --> [2:OK]
Oct 02 20:13:05.90: [ 7351]: <-- [5:ATM0\r]
Oct 02 20:13:06.06: [ 7351]: --> [2:OK]
Oct 02 20:13:06.06: [ 7351]: STATE CHANGE: RUNNING -> SENDING
Oct 02 20:13:06.06: [ 7351]: MODEM input buffering enabled
Oct 02 20:13:06.06: [ 7351]: Apply DialString rules to "xxxxxxx"
Oct 02 20:13:06.06: [ 7351]: --> return result "xxxxxxx"
Oct 02 20:13:06.06: [ 7351]: <-- [12:AT+FCLASS=2\r]
Oct 02 20:13:06.32: [ 7351]: --> [2:OK]
Oct 02 20:13:06.32: [ 7351]: <-- [10:AT+FTBC=0\r]
Oct 02 20:13:06.60: [ 7351]: --> [2:OK]
Oct 02 20:13:06.60: [ 7351]: <-- [10:AT+FBOR=0\r]
Oct 02 20:13:06.88: [ 7351]: --> [2:OK]
Oct 02 20:13:06.88: [ 7351]: <-- [13:AT+FPHCTO=30\r]
Oct 02 20:13:07.16: [ 7351]: --> [2:OK]
Oct 02 20:13:07.16: [ 7351]: <-- [10:AT+FBUG=1\r]
Oct 02 20:13:07.44: [ 7351]: --> [2:OK]
Oct 02 20:13:07.44: [ 7351]: <-- [24:AT+FDCC=1,5,2,2,2,0,0,0\r]
Oct 02 20:13:07.72: [ 7351]: --> [2:OK]
Oct 02 20:13:07.72: [ 7351]: <-- [12:AT+FLID=" "\r]
Oct 02 20:13:08.00: [ 7351]: --> [2:OK]
Oct 02 20:13:08.00: [ 7351]: DIAL xxxxxxx
Oct 02 20:13:08.00: [ 7351]: <-- [13:ATDTxxxxxxx@\r]
Oct 02 20:13:35.52: [ 7351]: --> [5:+FCON]
Oct 02 20:13:38.40: [ 7351]: --> [74:+FHR:FF 03 40 34 39 38 33 20 37 32 35 
20 33 30 36 20 20 20 20 20 20 20 20 ]
Oct 02 20:13:38.58: [ 7351]: --> [26:+FHR:FF 13 80 00 EE B8 44 ]
Oct 02 20:13:38.58: [ 7351]: --> [111:+FNSF:00 00 31 00 EE B8 44 84 0D DD 
00 00 DD DD 00 00 DD DD DD DD DD 01 10 02 02 21 11 27 ED 21 90 00 00 B4 01 ]
Oct 02 20:13:38.58: [ 7351]: REMOTE NSF "00 00 31 00 EE B8 44 84 0D DD 00 
00 DD DD 00 00 DD DD DD DD DD 01 10 02 02 21 11 27 ED 21 90 00 00 B4 01"
Oct 02 20:13:38.58: [ 7351]: NSF remote fax equipment: unknown
Oct 02 20:13:38.72: [ 7351]: --> [28:+FCSI:"        603 xxx xxxx"]
Oct 02 20:13:38.72: [ 7351]: REMOTE CSI "603 xxx xxxx"
Oct 02 20:13:38.72: [ 7351]: --> [21:+FDIS:1,5,0,2,1,2,0,4]
Oct 02 20:13:38.72: [ 7351]: --> [2:OK]
Oct 02 20:13:38.72: [ 7351]: REMOTE best rate 14400 bit/s
Oct 02 20:13:38.72: [ 7351]: REMOTE max page width 1728 pixels in 215 mm
Oct 02 20:13:38.72: [ 7351]: REMOTE max unlimited page length
Oct 02 20:13:38.72: [ 7351]: REMOTE best vres 7.7 line/mm
Oct 02 20:13:38.72: [ 7351]: REMOTE best format 2-D MR
Oct 02 20:13:38.72: [ 7351]: REMOTE supports T.30 Annex C, half duplex ECM
Oct 02 20:13:38.72: [ 7351]: REMOTE best 20 ms, 10 ms/scanline
Oct 02 20:13:38.72: [ 7351]: USE 14400 bit/s
Oct 02 20:13:38.72: [ 7351]: USE 20 ms, 10 ms/scanline
Oct 02 20:13:38.72: [ 7351]: SEND file "docq/doc8925.ps;31"
Oct 02 20:13:38.72: [ 7351]: USE page width 1728 pixels in 215 mm
Oct 02 20:13:38.72: [ 7351]: USE unlimited page length
Oct 02 20:13:38.72: [ 7351]: USE 7.7 line/mm
Oct 02 20:13:38.72: [ 7351]: USE 1-D MR
Oct 02 20:13:38.72: [ 7351]: <-- [24:AT+FDIS=1,5,0,2,0,0,0,4\r]
Oct 02 20:13:39.00: [ 7351]: --> [2:OK]
Oct 02 20:13:39.00: [ 7351]: <-- [7:AT+FDT\r]
Oct 02 20:13:40.20: [ 7351]: --> [74:+FHT:FF 03 43 20 20 20 20 20 20 20 20 
20 20 20 20 20 20 20 20 20 20 20 20 ]
Oct 02 20:13:41.00: [ 7351]: --> [26:+FHT:FF 13 83 00 62 A8 00 ]
Oct 02 20:13:45.88: [ 7351]: --> [14:+FHR:FF 13 84 ]
Oct 02 20:13:45.88: [ 7351]: --> [21:+FDCS:1,5,0,2,0,0,0,3]
Oct 02 20:13:45.88: [ 7351]: --> [7:CONNECT]
Oct 02 20:13:45.88: [ 7351]: SEND wait for XON
Oct 02 20:13:45.88: [ 7351]: --> [1:]
Oct 02 20:13:45.88: [ 7351]: SEND begin page
Oct 02 20:13:45.88: [ 7351]: <-- data [1030]
Oct 02 20:13:45.88: [ 7351]: <-- data [1026]
Oct 02 20:13:45.88: [ 7351]: <-- data [1026]
Oct 02 20:13:45.88: [ 7351]: <-- data [1026]
Oct 02 20:13:46.90: [ 7351]: <-- data [1025]
Oct 02 20:13:46.90: [ 7351]: <-- data [1025]
Oct 02 20:13:46.90: [ 7351]: <-- data [1025]
Oct 02 20:13:46.90: [ 7351]: <-- data [1026]
Oct 02 20:13:51.10: [ 7351]: <-- data [1026]
Oct 02 20:13:51.10: [ 7351]: <-- data [1026]
Oct 02 20:13:51.10: [ 7351]: <-- data [1024]
Oct 02 20:13:51.10: [ 7351]: <-- data [1024]
Oct 02 20:13:53.22: [ 7351]: <-- data [1025]
Oct 02 20:13:53.22: [ 7351]: <-- data [1026]
Oct 02 20:13:53.22: [ 7351]: <-- data [1024]
Oct 02 20:13:53.22: [ 7351]: <-- data [1026]
Oct 02 20:13:55.66: [ 7351]: <-- data [1025]
Oct 02 20:13:55.66: [ 7351]: <-- data [1024]
Oct 02 20:13:55.66: [ 7351]: <-- data [1026]
Oct 02 20:13:55.66: [ 7351]: <-- data [1025]
Oct 02 20:13:58.10: [ 7351]: <-- data [1029]
Oct 02 20:13:58.10: [ 7351]: <-- data [1027]
Oct 02 20:13:58.10: [ 7351]: <-- data [1025]
Oct 02 20:14:00.26: [ 7351]: <-- data [1024]
Oct 02 20:14:00.26: [ 7351]: <-- data [1024]
Oct 02 20:14:00.26: [ 7351]: <-- data [1025]
Oct 02 20:14:00.26: [ 7351]: <-- data [1025]
Oct 02 20:14:03.90: [ 7351]: <-- data [1025]
Oct 02 20:14:03.90: [ 7351]: <-- data [1024]
Oct 02 20:14:03.90: [ 7351]: <-- data [1024]
Oct 02 20:14:03.90: [ 7351]: <-- data [1026]
Oct 02 20:14:06.42: [ 7351]: <-- data [1025]
Oct 02 20:14:06.42: [ 7351]: <-- data [1026]
Oct 02 20:14:06.42: [ 7351]: <-- data [1024]
Oct 02 20:14:06.42: [ 7351]: <-- data [1024]
Oct 02 20:14:08.78: [ 7351]: <-- data [1025]
Oct 02 20:14:08.78: [ 7351]: <-- data [1025]
Oct 02 20:14:08.78: [ 7351]: <-- data [1024]
Oct 02 20:14:08.78: [ 7351]: <-- data [1025]
Oct 02 20:14:10.90: [ 7351]: <-- data [1025]
Oct 02 20:14:10.90: [ 7351]: <-- data [1024]
Oct 02 20:14:10.90: [ 7351]: <-- data [1024]
Oct 02 20:14:10.90: [ 7351]: <-- data [1025]
Oct 02 20:14:12.86: [ 7351]: <-- data [1024]
Oct 02 20:14:12.86: [ 7351]: <-- data [1024]
Oct 02 20:14:12.86: [ 7351]: <-- data [1025]
Oct 02 20:14:15.06: [ 7351]: <-- data [1025]
Oct 02 20:14:15.06: [ 7351]: <-- data [1024]
Oct 02 20:14:15.06: [ 7351]: <-- data [1024]
Oct 02 20:14:15.06: [ 7351]: <-- data [1024]
Oct 02 20:14:17.50: [ 7351]: <-- data [1026]
Oct 02 20:14:17.50: [ 7351]: <-- data [1024]
Oct 02 20:14:17.50: [ 7351]: <-- data [1024]
Oct 02 20:14:17.50: [ 7351]: <-- data [1026]
Oct 02 20:14:19.54: [ 7351]: <-- data [1024]
Oct 02 20:14:19.54: [ 7351]: <-- data [1027]
Oct 02 20:14:19.54: [ 7351]: <-- data [1030]
Oct 02 20:14:19.54: [ 7351]: <-- data [1026]
Oct 02 20:14:21.50: [ 7351]: <-- data [1025]
Oct 02 20:14:21.50: [ 7351]: <-- data [1033]
Oct 02 20:14:21.50: [ 7351]: <-- data [1024]
Oct 02 20:14:24.30: [ 7351]: <-- data [1026]
Oct 02 20:14:24.30: [ 7351]: <-- data [1024]
Oct 02 20:14:24.30: [ 7351]: <-- data [1025]
Oct 02 20:14:24.30: [ 7351]: <-- data [1025]
Oct 02 20:14:27.38: [ 7351]: <-- data [1025]
Oct 02 20:14:27.38: [ 7351]: <-- data [1025]
Oct 02 20:14:27.38: [ 7351]: <-- data [1024]
Oct 02 20:14:27.38: [ 7351]: <-- data [1027]
Oct 02 20:14:29.90: [ 7351]: <-- data [1027]
Oct 02 20:14:29.90: [ 7351]: <-- data [1024]
Oct 02 20:14:29.90: [ 7351]: <-- data [1027]
Oct 02 20:14:29.90: [ 7351]: <-- data [1028]
Oct 02 20:14:31.94: [ 7351]: <-- data [1027]
Oct 02 20:14:31.94: [ 7351]: <-- data [196]
Oct 02 20:14:31.94: [ 7351]: SENT 75972 bytes of data
Oct 02 20:14:31.94: [ 7351]: <-- data [2]
Oct 02 20:14:31.94: [ 7351]: SEND end page
Oct 02 20:14:35.52: [ 7351]: --> [136:]
Oct 02 20:14:35.52: [ 7351]: --> [2:OK]
Oct 02 20:14:35.52: [ 7351]: SEND send MPS (more pages, same document)
Oct 02 20:14:35.52: [ 7351]: <-- [9:AT+FET=0\r]
Oct 02 20:14:38.88: [ 7351]: --> [14:+FHT:FF 13 4F ]
Oct 02 20:14:40.48: [ 7351]: --> [14:+FHR:FF 13 8C ]
Oct 02 20:14:40.48: [ 7351]: --> [7:+FPTS:1]
Oct 02 20:14:40.48: [ 7351]: --> [2:OK]
Oct 02 20:14:40.48: [ 7351]: SEND recv MCF (message confirmation)
Oct 02 20:14:40.48: [ 7351]: SEND FAX (00018197): FROM faxuser 
@redhat7.sldsi.com TO xxxxxxx (page 1 of 2 sent in 1:02)
Oct 02 20:14:40.48: [ 7351]: SEND FAX (00018197): FROM faxuser 
@redhat7.sldsi.com TO xxxxxxx (docq/doc8925.ps;31 sent in 1:02)
Oct 02 20:14:40.48: [ 7351]: SEND file "docq/doc8926.ps;31"
Oct 02 20:14:40.48: [ 7351]: USE page width 1728 pixels in 215 mm
Oct 02 20:14:40.48: [ 7351]: USE unlimited page length
Oct 02 20:14:40.48: [ 7351]: USE 7.7 line/mm
Oct 02 20:14:40.48: [ 7351]: USE 1-D MR
Oct 02 20:14:40.48: [ 7351]: <-- [7:AT+FDT\r]
Oct 02 20:14:40.72: [ 7351]: --> [7:CONNECT]
Oct 02 20:14:40.72: [ 7351]: SEND wait for XON
Oct 02 20:14:40.72: [ 7351]: --> [1:]
Oct 02 20:14:40.72: [ 7351]: SEND begin page
Oct 02 20:14:40.72: [ 7351]: <-- data [1028]
Oct 02 20:14:40.72: [ 7351]: <-- data [1026]
Oct 02 20:14:40.72: [ 7351]: <-- data [1024]
Oct 02 20:14:40.72: [ 7351]: <-- data [1025]
Oct 02 20:14:41.74: [ 7351]: <-- data [1031]
Oct 02 20:14:41.74: [ 7351]: <-- data [1025]
Oct 02 20:14:41.74: [ 7351]: <-- data [328]
Oct 02 20:14:41.74: [ 7351]: SENT 6471 bytes of data
Oct 02 20:14:41.74: [ 7351]: <-- data [2]
Oct 02 20:14:41.74: [ 7351]: SEND end page
Oct 02 20:14:53.60: [ 7351]: --> [8:]
Oct 02 20:14:53.60: [ 7351]: --> [2:OK]
Oct 02 20:14:53.60: [ 7351]: SEND send EOP (no more pages or documents)
Oct 02 20:14:53.60: [ 7351]: <-- [9:AT+FET=2\r]
Oct 02 20:14:56.68: [ 7351]: --> [14:+FHT:FF 13 2F ]
Oct 02 20:14:58.28: [ 7351]: --> [14:+FHR:FF 13 8C ]
Oct 02 20:14:58.28: [ 7351]: --> [7:+FPTS:1]
Oct 02 20:14:59.28: [ 7351]: --> [14:+FHT:FF 13 FB ]
Oct 02 20:14:59.76: [ 7351]: --> [7:+FHNG:0]
Oct 02 20:14:59.76: [ 7351]: REMOTE HANGUP: Normal and proper end of 
connection(code 0)
Oct 02 20:14:59.76: [ 7351]: SEND recv MCF (message confirmation)
Oct 02 20:14:59.76: [ 7351]: SEND FAX (00018197): FROM faxuser 
@redhat7.sldsi.com TO xxxxxxx (page 2 of 2 sent in 0:19)
Oct 02 20:14:59.76: [ 7351]: SEND FAX (00018197): FROM faxuser 
@redhat7.sldsi.com TO xxxxxxx (docq/doc8926.ps;31 sent in 0:19)
Oct 02 20:14:59.76: [ 7351]: <-- [5:ATH0\r]
Oct 02 20:15:00.32: [ 7351]: --> [2:OK]
Oct 02 20:15:00.32: [ 7351]: MODEM set DTR OFF
Oct 02 20:15:00.32: [ 7351]: STATE CHANGE: SENDING -> MODEMWAIT (timeout 5)
Oct 02 20:15:00.32: [ 7351]: SESSION END

--------------------------------------
Jeff Herring  /  jeffh@sldsi.com
Seacoast Laboratory Data Systems, Inc.
Voice:  603 431 4114  x14
FAX:    603 431 2112
--------------------------------------



____________________ HylaFAX(tm) Users Mailing List _______________________
 To unsub: mail -s unsubscribe hylafax-users-request@hylafax.org < /dev/null





Project hosted by iFAX Solutions