![]() |
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