HylaFAX The world's most advanced open source fax server

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

[hylafax-users] RTNHandlingMethod still functional?



Linux rh6x, 

HylaFAX 4.1  (bugzilla id's)
    + cvs-20010827:
          tsieop-52 eom-117 cid-139 dso-141 eop-152 bulk-153 faxqcl-160
          dest-172 detect-181 msgdelay-185
    + other:
          log-51 log-prio switchdelay-193 ring-157
          class1waitcmd-197 (revert eop-152)

Today I got an RTN, when I noted it in the logs I tried reproducing but the
remote modem fax is not available anymore

The weird thing is that HylaFAX didn't honor the
RTNHandlingMethod:              Ignore
config setting.

Also, the fax was apparently sent, but HylaFAX said

Internal botch; bad  post-page handling string ""

here's the log, no debug since the remote fax is not available right now.

so the questions are:
1) is it possible that recent changes disabled RTNHandlingMethod?
2) is "Internal botch" due to HylaFAX mishandling the connection or is it a real
line/protocol issue.

===
Oct 12 09:34:28.61: [ 4944]: SESSION BEGIN 00006027 39yyyyxxxxx
Oct 12 09:34:28.61: [ 4944]: HylaFAX (tm) Version 4.1
Oct 12 09:34:28.61: [ 4944]: SEND FAX: JOB 3078 DEST yyyy-xxxxx COMMID 00006027
DEVICE '/dev/ttyS2'
Oct 12 09:34:28.61: [ 4944]: DELAY 75 ms
Oct 12 09:34:28.68: [ 4944]: DELAY 2600 ms
Oct 12 09:34:31.29: [ 4944]: <-- [4:ATZ\r]
Oct 12 09:34:31.41: [ 4944]: --> [2:OK]
Oct 12 09:34:31.41: [ 4944]: <-- [7:AT%TCB\r]
Oct 12 09:34:31.42: [ 4944]: --> [6:AT%TCB]
Oct 12 09:34:31.42: [ 4944]: --> [2:OK]
Oct 12 09:34:31.42: [ 4944]: <-- [5:ATE0\r]
Oct 12 09:34:31.43: [ 4944]: --> [4:ATE0]
Oct 12 09:34:31.43: [ 4944]: --> [2:OK]
Oct 12 09:34:31.43: [ 4944]: <-- [5:ATV1\r]
Oct 12 09:34:31.44: [ 4944]: --> [2:OK]
Oct 12 09:34:31.44: [ 4944]: <-- [7:ATQ0X3\r]
Oct 12 09:34:31.45: [ 4944]: --> [2:OK]
Oct 12 09:34:31.45: [ 4944]: <-- [7:ATS0=0\r]
Oct 12 09:34:31.47: [ 4944]: --> [2:OK]
Oct 12 09:34:31.47: [ 4944]: <-- [7:ATS8=2\r]
Oct 12 09:34:31.49: [ 4944]: --> [2:OK]
Oct 12 09:34:31.49: [ 4944]: <-- [8:ATS7=60\r]
Oct 12 09:34:31.51: [ 4944]: --> [2:OK]
Oct 12 09:34:31.51: [ 4944]: <-- [6:AT&K4\r]
Oct 12 09:34:31.52: [ 4944]: --> [2:OK]
Oct 12 09:34:31.52: [ 4944]: <-- [6:AT&D3\r]
Oct 12 09:34:31.53: [ 4944]: --> [2:OK]
Oct 12 09:34:31.53: [ 4944]: <-- [6:AT&C1\r]
Oct 12 09:34:31.54: [ 4944]: --> [2:OK]
Oct 12 09:34:31.54: [ 4944]: <-- [12:AT+FCLASS=1\r]
Oct 12 09:34:31.56: [ 4944]: --> [2:OK]
Oct 12 09:34:31.56: [ 4944]: <-- [5:ATM0\r]
Oct 12 09:34:31.57: [ 4944]: --> [2:OK]
Oct 12 09:34:31.57: [ 4944]: sched policy=1, priority=1
Oct 12 09:34:31.58: [ 4944]: <-- [12:AT+FCLASS=1\r]
Oct 12 09:34:31.69: [ 4944]: --> [2:OK]
Oct 12 09:34:31.70: [ 4944]: DIAL wwwww,yyyyxxxxx
Oct 12 09:34:31.70: [ 4944]: <-- [21:ATDTwwwww,yyyyxxxxx@\r]
Oct 12 09:35:16.79: [ 4944]: --> [7:CONNECT]
Oct 12 09:35:18.65: [ 4944]: --> [2:OK]
Oct 12 09:35:18.65: [ 4944]: REMOTE NSF "00 00 0E 00 00 00 96 0F 01 02 00 10 05
02 85 C8 08 01 49 02 4F 52 54 4F 46 52 55 54 54 41 20 52 41 50 41 4C 03 11"
Oct 12 09:35:18.65: [ 4944]: NSF remote fax equipment: Panasonic KX-F90
Oct 12 09:35:18.65: [ 4944]: NSF remote station ID: "REMOTE STAT ID  "
Oct 12 09:35:18.65: [ 4944]: <-- [9:AT+FRH=3\r]
Oct 12 09:35:18.67: [ 4944]: --> [7:CONNECT]
Oct 12 09:35:19.42: [ 4944]: --> [2:OK]
Oct 12 09:35:19.42: [ 4944]: REMOTE CSI "yyyy 53290"
Oct 12 09:35:19.42: [ 4944]: <-- [9:AT+FRH=3\r]
Oct 12 09:35:19.44: [ 4944]: --> [7:CONNECT]
Oct 12 09:35:19.74: [ 4944]: --> [2:OK]
Oct 12 09:35:19.74: [ 4944]: REMOTE best rate 9600 bit/s
Oct 12 09:35:19.74: [ 4944]: REMOTE max page width 1728 pixels in 215 mm
Oct 12 09:35:19.74: [ 4944]: REMOTE max unlimited page length 
Oct 12 09:35:19.74: [ 4944]: REMOTE best vres 7.7 line/mm
Oct 12 09:35:19.74: [ 4944]: REMOTE best format 1-D MR
Oct 12 09:35:19.74: [ 4944]: REMOTE best 20 ms, 10 ms/scanline
Oct 12 09:35:19.74: [ 4944]: USE 9600 bit/s
Oct 12 09:35:19.74: [ 4944]: USE 20 ms, 10 ms/scanline
Oct 12 09:35:19.74: [ 4944]: SEND file "docq/doc3099.ps;01"
Oct 12 09:35:19.74: [ 4944]: USE page width 1728 pixels in 215 mm
Oct 12 09:35:19.74: [ 4944]: USE unlimited page length 
Oct 12 09:35:19.74: [ 4944]: USE 7.7 line/mm
Oct 12 09:35:19.74: [ 4944]: USE 1-D MR
Oct 12 09:35:19.74: [ 4944]: SEND training at v.29 9600 bit/s
Oct 12 09:35:19.74: [ 4944]: <-- [9:AT+FTH=3\r]
Oct 12 09:35:19.79: [ 4944]: --> [7:CONNECT]
Oct 12 09:35:19.79: [ 4944]: <-- data [23]
Oct 12 09:35:19.79: [ 4944]: <-- data [2]
Oct 12 09:35:21.58: [ 4944]: --> [7:CONNECT]
Oct 12 09:35:21.58: [ 4944]: <-- data [6]
Oct 12 09:35:21.58: [ 4944]: <-- data [2]
Oct 12 09:35:22.01: [ 4944]: --> [2:OK]
Oct 12 09:35:22.01: [ 4944]: <-- [9:AT+FTS=7\r]
Oct 12 09:35:22.11: [ 4944]: --> [2:OK]
Oct 12 09:35:22.11: [ 4944]: <-- [10:AT+FTM=96\r]
Oct 12 09:35:22.17: [ 4944]: --> [7:CONNECT]
Oct 12 09:35:22.17: [ 4944]: <-- data [1024]
Oct 12 09:35:22.17: [ 4944]: <-- data [776]
Oct 12 09:35:22.17: [ 4944]: <-- data [2]
Oct 12 09:35:24.13: [ 4944]: --> [2:OK]
Oct 12 09:35:24.13: [ 4944]: <-- [9:AT+FRH=3\r]
Oct 12 09:35:25.42: [ 4944]: --> [7:CONNECT]
Oct 12 09:35:26.42: [ 4944]: --> [2:OK]
Oct 12 09:35:26.42: [ 4944]: TRAINING succeeded
Oct 12 09:35:26.42: [ 4944]: DELAY 75 ms
Oct 12 09:35:26.50: [ 4944]: <-- [10:AT+FTM=96\r]
Oct 12 09:35:26.57: [ 4944]: --> [7:CONNECT]
Oct 12 09:35:26.57: [ 4944]: SEND begin page
Oct 12 09:35:26.60: [ 4944]: <-- data [1026]
Oct 12 09:35:26.60: [ 4944]: <-- data [1028]
Oct 12 09:35:26.60: [ 4944]: <-- data [1030]
Oct 12 09:35:26.60: [ 4944]: <-- data [1028]
Oct 12 09:35:28.01: [ 4944]: <-- data [1024]
Oct 12 09:35:28.01: [ 4944]: <-- data [1034]
Oct 12 09:35:28.94: [ 4944]: <-- data [1032]
Oct 12 09:35:28.94: [ 4944]: <-- data [1024]
Oct 12 09:35:29.87: [ 4944]: <-- data [1027]
Oct 12 09:35:30.81: [ 4944]: <-- data [1026]
Oct 12 09:35:31.75: [ 4944]: <-- data [1028]
Oct 12 09:35:32.68: [ 4944]: <-- data [1024]
Oct 12 09:35:33.61: [ 4944]: <-- data [1024]
Oct 12 09:35:34.54: [ 4944]: <-- data [1024]
Oct 12 09:35:35.47: [ 4944]: <-- data [1025]
Oct 12 09:35:36.39: [ 4944]: <-- data [1027]
Oct 12 09:35:37.31: [ 4944]: <-- data [1026]
Oct 12 09:35:38.23: [ 4944]: <-- data [1024]
Oct 12 09:35:39.15: [ 4944]: <-- data [1028]
Oct 12 09:35:39.15: [ 4944]: <-- data [1030]
Oct 12 09:35:40.08: [ 4944]: <-- data [1027]
Oct 12 09:35:41.01: [ 4944]: <-- data [1029]
Oct 12 09:35:41.93: [ 4944]: <-- data [1026]
Oct 12 09:35:42.86: [ 4944]: <-- data [1026]
Oct 12 09:35:43.79: [ 4944]: <-- data [1027]
Oct 12 09:35:44.72: [ 4944]: <-- data [1028]
Oct 12 09:35:45.65: [ 4944]: <-- data [878]
Oct 12 09:35:46.58: [ 4944]: SENT 27498 bytes of data
Oct 12 09:35:46.59: [ 4944]: <-- data [1029]
Oct 12 09:35:47.50: [ 4944]: <-- data [1027]
Oct 12 09:35:48.43: [ 4944]: <-- data [1026]
Oct 12 09:35:48.43: [ 4944]: <-- data [1027]
Oct 12 09:35:49.36: [ 4944]: <-- data [1030]
Oct 12 09:35:50.31: [ 4944]: <-- data [1032]
Oct 12 09:35:51.24: [ 4944]: <-- data [1029]
Oct 12 09:35:52.16: [ 4944]: <-- data [1029]
Oct 12 09:35:53.09: [ 4944]: <-- data [1027]
Oct 12 09:35:54.03: [ 4944]: <-- data [1028]
Oct 12 09:35:54.97: [ 4944]: <-- data [1029]
Oct 12 09:35:55.90: [ 4944]: <-- data [1027]
Oct 12 09:35:56.83: [ 4944]: <-- data [1026]
Oct 12 09:35:57.76: [ 4944]: <-- data [1025]
Oct 12 09:35:58.69: [ 4944]: <-- data [1027]
Oct 12 09:35:58.69: [ 4944]: <-- data [1029]
Oct 12 09:35:59.62: [ 4944]: <-- data [1024]
Oct 12 09:36:00.55: [ 4944]: <-- data [1024]
Oct 12 09:36:01.48: [ 4944]: <-- data [1024]
Oct 12 09:36:02.41: [ 4944]: <-- data [1024]
Oct 12 09:36:03.34: [ 4944]: <-- data [1024]
Oct 12 09:36:04.26: [ 4944]: <-- data [1024]
Oct 12 09:36:05.18: [ 4944]: <-- data [1024]
Oct 12 09:36:06.10: [ 4944]: <-- data [160]
Oct 12 09:36:06.10: [ 4944]: SENT 23712 bytes of data
Oct 12 09:36:06.10: [ 4944]: SEND 1D RTC
Oct 12 09:36:06.10: [ 4944]: <-- data [29]
Oct 12 09:36:06.10: [ 4944]: <-- data [2]
Oct 12 09:36:06.10: [ 4944]: SEND end page
Oct 12 09:36:09.75: [ 4944]: --> [2:OK]
Oct 12 09:36:09.75: [ 4944]: <-- [9:AT+FTS=9\r]
Oct 12 09:36:09.86: [ 4944]: --> [2:OK]
Oct 12 09:36:09.86: [ 4944]: SEND send EOP (no more pages or documents)
Oct 12 09:36:09.86: [ 4944]: <-- [9:AT+FTH=3\r]
Oct 12 09:36:09.92: [ 4944]: --> [7:CONNECT]
Oct 12 09:36:09.92: [ 4944]: <-- data [3]
Oct 12 09:36:09.92: [ 4944]: <-- data [2]
Oct 12 09:36:11.23: [ 4944]: --> [2:OK]
Oct 12 09:36:11.23: [ 4944]: <-- [9:AT+FRH=3\r]
Oct 12 09:36:12.03: [ 4944]: --> [7:CONNECT]
Oct 12 09:36:13.00: [ 4944]: --> [2:OK]
Oct 12 09:36:13.00: [ 4944]: SEND recv RTN (retrain negative)
Oct 12 09:36:13.00: [ 4944]: SEND FAX (00006027): FROM user@host TO yyyy-xxxxx
(page 1 of 1 sent in 0:54)
Oct 12 09:36:13.00: [ 4944]: SEND training at v.29 7200 bit/s
Oct 12 09:36:13.00: [ 4944]: <-- [9:AT+FTH=3\r]
Oct 12 09:36:13.05: [ 4944]: --> [7:CONNECT]
Oct 12 09:36:13.05: [ 4944]: <-- data [23]
Oct 12 09:36:13.05: [ 4944]: <-- data [2]
Oct 12 09:36:14.84: [ 4944]: --> [7:CONNECT]
Oct 12 09:36:14.84: [ 4944]: <-- data [6]
Oct 12 09:36:14.84: [ 4944]: <-- data [2]
Oct 12 09:36:15.28: [ 4944]: --> [2:OK]
Oct 12 09:36:15.28: [ 4944]: <-- [9:AT+FTS=7\r]
Oct 12 09:36:15.37: [ 4944]: --> [2:OK]
Oct 12 09:36:15.37: [ 4944]: <-- [10:AT+FTM=72\r]
Oct 12 09:36:15.44: [ 4944]: --> [7:CONNECT]
Oct 12 09:36:15.44: [ 4944]: <-- data [1024]
Oct 12 09:36:15.44: [ 4944]: <-- data [326]
Oct 12 09:36:15.44: [ 4944]: <-- data [2]
Oct 12 09:36:17.39: [ 4944]: --> [2:OK]
Oct 12 09:36:17.39: [ 4944]: <-- [9:AT+FRH=3\r]
Oct 12 09:36:18.68: [ 4944]: --> [7:CONNECT]
Oct 12 09:36:19.65: [ 4944]: --> [2:OK]
Oct 12 09:36:19.65: [ 4944]: TRAINING succeeded
Oct 12 09:36:19.65: [ 4944]: DELAY 75 ms
Oct 12 09:36:19.73: [ 4944]: <-- [10:AT+FTM=72\r]
Oct 12 09:36:19.80: [ 4944]: --> [7:CONNECT]
Oct 12 09:36:19.80: [ 4944]: SEND begin page
Oct 12 09:36:19.80: [ 4944]: <-- data [1026]
Oct 12 09:36:19.80: [ 4944]: <-- data [1031]
Oct 12 09:36:19.80: [ 4944]: <-- data [1027]
Oct 12 09:36:19.80: [ 4944]: <-- data [1028]
Oct 12 09:36:21.12: [ 4944]: <-- data [1024]
Oct 12 09:36:21.12: [ 4944]: <-- data [1034]
Oct 12 09:36:22.00: [ 4944]: <-- data [1032]
Oct 12 09:36:22.89: [ 4944]: <-- data [1024]
Oct 12 09:36:24.64: [ 4944]: <-- data [1028]
Oct 12 09:36:25.53: [ 4944]: <-- data [1025]
Oct 12 09:36:26.43: [ 4944]: <-- data [1028]
Oct 12 09:36:27.33: [ 4944]: <-- data [1024]
Oct 12 09:36:29.11: [ 4944]: <-- data [1024]
Oct 12 09:36:30.00: [ 4944]: <-- data [1024]
Oct 12 09:36:30.89: [ 4944]: <-- data [1027]
Oct 12 09:36:32.64: [ 4944]: <-- data [1027]
Oct 12 09:36:33.51: [ 4944]: <-- data [1024]
Oct 12 09:36:34.38: [ 4944]: <-- data [1028]
Oct 12 09:36:35.26: [ 4944]: <-- data [1030]
Oct 12 09:36:37.03: [ 4944]: <-- data [1028]
Oct 12 09:36:37.92: [ 4944]: <-- data [145]
Oct 12 09:36:37.92: [ 4944]: SENT 20624 bytes of data
Oct 12 09:36:37.92: [ 4944]: <-- data [1028]
Oct 12 09:36:39.69: [ 4944]: <-- data [1027]
Oct 12 09:36:40.57: [ 4944]: <-- data [1025]
Oct 12 09:36:41.46: [ 4944]: <-- data [1028]
Oct 12 09:36:42.34: [ 4944]: <-- data [1030]
Oct 12 09:36:44.12: [ 4944]: <-- data [1029]
Oct 12 09:36:45.00: [ 4944]: <-- data [1029]
Oct 12 09:36:45.87: [ 4944]: <-- data [1024]
Oct 12 09:36:47.64: [ 4944]: <-- data [1028]
Oct 12 09:36:48.53: [ 4944]: <-- data [1029]
Oct 12 09:36:49.42: [ 4944]: <-- data [1032]
Oct 12 09:36:50.30: [ 4944]: <-- data [1031]
Oct 12 09:36:52.06: [ 4944]: <-- data [1030]
Oct 12 09:36:52.95: [ 4944]: <-- data [1027]
Oct 12 09:36:53.83: [ 4944]: <-- data [1028]
Oct 12 09:36:55.60: [ 4944]: <-- data [1027]
Oct 12 09:36:56.50: [ 4944]: <-- data [1027]
Oct 12 09:36:57.38: [ 4944]: <-- data [1026]
Oct 12 09:36:58.27: [ 4944]: <-- data [1028]
Oct 12 09:37:00.04: [ 4944]: <-- data [1028]
Oct 12 09:37:00.92: [ 4944]: <-- data [141]
Oct 12 09:37:00.92: [ 4944]: SENT 20621 bytes of data
Oct 12 09:37:00.92: [ 4944]: <-- data [1024]
Oct 12 09:37:01.79: [ 4944]: <-- data [1024]
Oct 12 09:37:03.53: [ 4944]: <-- data [1024]
Oct 12 09:37:04.41: [ 4944]: <-- data [1024]
Oct 12 09:37:05.29: [ 4944]: <-- data [1024]
Oct 12 09:37:07.05: [ 4944]: <-- data [10]
Oct 12 09:37:07.05: [ 4944]: SENT 5130 bytes of data
Oct 12 09:37:07.05: [ 4944]: SEND 1D RTC
Oct 12 09:37:07.05: [ 4944]: <-- data [29]
Oct 12 09:37:07.05: [ 4944]: <-- data [2]
Oct 12 09:37:07.05: [ 4944]: SEND end page
Oct 12 09:37:11.84: [ 4944]: --> [2:OK]
Oct 12 09:37:11.84: [ 4944]: <-- [9:AT+FTH=3\r]
Oct 12 09:37:11.89: [ 4944]: --> [7:CONNECT]
Oct 12 09:37:11.89: [ 4944]: <-- data [3]
Oct 12 09:37:11.89: [ 4944]: <-- data [2]
Oct 12 09:37:13.21: [ 4944]: --> [2:OK]
Oct 12 09:37:13.21: [ 4944]: <-- [14:AT+FCLASS=0H0\r]
Oct 12 09:37:15.98: [ 4944]: --> [2:OK]
Oct 12 09:37:15.98: [ 4944]: sched policy=0, priority=0
Oct 12 09:37:15.98: [ 4944]: SESSION END

===

-- 
giulioo@pobox.com


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





Project hosted by iFAX Solutions