Re: [hylafax-users] Regarding USR5610 Modem

[Philip Walls <pawalls@xxxxxxxxx>]

I've attached a transcript from the receiving modem, as well as from the
sending modem (both USR5610) to give you a better idea of what's
happening. I tried to make what I could of the information regarding the
communication you provided, and it looks like it receives a PPS/MPS but
breaks directly after that.

Oddly enough, I sent two faxes successfully using the same exact
document/command before I was able to reproduce this error again. It
seems somewhat intermittent. I hope the information attached is
sufficient. Thankyou for your quick response and assistance.


On Mon, 2005-02-21 at 19:24 -0800, Lee Howard wrote:
>On 2005.02.21 15:19 Philip Walls wrote:
>> I've read on several threads of users having difficulty with this
>> modem
>> (USR 5610 rev 01). I was just curious if there is any known way to get
>> around the "No response to PPS repeated 3 times." issue as this server
>> is already in production and I do not want to replace all 3 modems in
>> it.
>
>The communication pattern goes like this:
>
><-- DCS
><-- TCF
>--> CFR
><-- image data
><-- PPM (PPS)
>
>What you have to try to determine is whether the receiver is not 
>getting the image data, or whether it is not hearing the PPM signal.  
>So, you find out if the receiver is printing out the full page or not.  
>If it is, then something's going wrong after the image data is sent, 
>before the PPM signal.  If it isn't, then something is probably going 
>wrong either in the image data or in the timing between CFR and the 
>image data.
>
>In any case, a log would certainly help us to help you.
>
>Lee.
>
>____________________ HylaFAX(tm) Users Mailing List _______________________
>  To subscribe/unsubscribe, click http://lists.hylafax.org/cgi-bin/lsg2.cgi
> On UNIX: mail -s unsubscribe hylafax-users-request@xxxxxxxxxxx < /dev/null
>  *To learn about commercial HylaFAX(tm) support, mail sales@xxxxxxxxx*
-- 

Philip Walls
Network Administrator
Gleim Internet, Inc.
(352) 375-0772 x 116

Feb 22 11:22:32.67: [26950]: SESSION BEGIN 000000181 ###########
Feb 22 11:22:32.67: [26950]: HylaFAX (tm) Version 4.2.1
Feb 22 11:22:32.67: [26950]: <-- [13:AT+FCLASS=1A\r]
Feb 22 11:22:37.95: [26950]: --> [7:CONNECT]
Feb 22 11:22:37.95: [26950]: ANSWER: FAX CONNECTION  DEVICE '/dev/ttyS5'
Feb 22 11:22:37.95: [26950]: RECV FAX: begin
Feb 22 11:22:38.02: [26950]: --> [7:CONNECT]
Feb 22 11:22:38.74: [26950]: --> [7:CONNECT]
Feb 22 11:22:40.92: [26950]: --> [2:OK]
Feb 22 11:22:40.92: [26950]: <-- [9:AT+FRH=3\r]
Feb 22 11:22:41.28: [26950]: --> [7:CONNECT]
Feb 22 11:22:42.86: [26950]: --> [2:OK]
Feb 22 11:22:42.86: [26950]: REMOTE TSI "FaxModem1"
Feb 22 11:22:42.86: [26950]: <-- [9:AT+FRH=3\r]
Feb 22 11:22:42.87: [26950]: --> [7:CONNECT]
Feb 22 11:22:43.18: [26950]: --> [2:OK]
Feb 22 11:22:43.18: [26950]: REMOTE wants 14400 bit/s
Feb 22 11:22:43.18: [26950]: REMOTE wants A4 page width (215 mm)
Feb 22 11:22:43.18: [26950]: REMOTE wants unlimited page length
Feb 22 11:22:43.18: [26950]: REMOTE wants 3.85 line/mm
Feb 22 11:22:43.18: [26950]: REMOTE wants 2-D MMR
Feb 22 11:22:43.18: [26950]: REMOTE wants T.30 Annex A, 256-byte ECM
Feb 22 11:22:43.18: [26950]: RECV training at v.17 14400 bit/s
Feb 22 11:22:43.18: [26950]: <-- [11:AT+FRM=145\r]
Feb 22 11:22:44.74: [26950]: --> [7:CONNECT]
Feb 22 11:22:46.30: [26950]: RECV: TCF 2812 bytes, 3% non-zero, 2699 zero-run
Feb 22 11:22:46.30: [26950]: --> [10:NO CARRIER]
Feb 22 11:22:46.30: [26950]: DELAY 75 ms
Feb 22 11:22:46.38: [26950]: TRAINING succeeded
Feb 22 11:22:46.38: [26950]: <-- [9:AT+FTH=3\r]
Feb 22 11:22:46.57: [26950]: --> [7:CONNECT]
Feb 22 11:22:47.75: [26950]: --> [2:OK]
Feb 22 11:22:47.75: [26950]: <-- [11:AT+FRM=146\r]
Feb 22 11:22:48.34: [26950]: --> [7:CONNECT]
Feb 22 11:22:48.69: [26950]: RECV received frame number 0
Feb 22 11:22:48.84: [26950]: RECV received frame number 1
Feb 22 11:22:48.98: [26950]: RECV received frame number 2
Feb 22 11:22:49.12: [26950]: RECV received frame number 3
Feb 22 11:22:49.25: [26950]: RECV received frame number 4
Feb 22 11:22:49.40: [26950]: RECV received frame number 5
Feb 22 11:22:49.54: [26950]: RECV received frame number 6
Feb 22 11:22:49.75: [26950]: RECV received frame number 7
Feb 22 11:22:49.89: [26950]: RECV received frame number 8
Feb 22 11:22:50.03: [26950]: RECV received frame number 9
Feb 22 11:22:50.17: [26950]: RECV received frame number 10
Feb 22 11:22:50.31: [26950]: RECV received frame number 11
Feb 22 11:22:50.45: [26950]: RECV received frame number 12
Feb 22 11:22:50.59: [26950]: RECV received frame number 13
Feb 22 11:22:50.73: [26950]: RECV received frame number 14
Feb 22 11:22:50.94: [26950]: RECV received frame number 15
Feb 22 11:22:50.94: [26950]: RECV received RCP frame
Feb 22 11:22:51.05: [26950]: --> [10:NO CARRIER]
Feb 22 11:22:51.05: [26950]: <-- [9:AT+FRH=3\r]
Feb 22 11:22:51.23: [26950]: --> [7:CONNECT]
Feb 22 11:22:52.42: [26950]: --> [2:OK]
Feb 22 11:22:52.42: [26950]: RECV recv PPS (partial page signal)
Feb 22 11:22:52.42: [26950]: RECV recv MPS (more pages, same document)
Feb 22 11:22:52.42: [26950]: RECV received 16 frames of block 1 of page 1
Feb 22 11:22:52.43: [26950]: RECV: 4053 bytes of data, 1078 total lines
Feb 22 11:22:52.43: [26950]: <-- [9:AT+FRS=7\r]
Feb 22 11:22:55.98: [26950]: --> [2:OK]
Feb 22 11:22:55.99: [26950]: <-- [9:AT+FTH=3\r]
Feb 22 11:22:56.18: [26950]: --> [7:CONNECT]
Feb 22 11:22:56.18: [26950]: RECV send MCF (message confirmation)
Feb 22 11:22:56.18: [26950]: RECV FAX (000000181): from FaxModem1, page 1 in 0:10, INF, 3.85 line/mm, 2-D MMR, 14400 bit/s
Feb 22 11:22:57.35: [26950]: --> [2:OK]
Feb 22 11:22:57.35: [26950]: <-- [11:AT+FRM=146\r]
Feb 22 11:23:04.46: [26950]: --> [2:OK]
Feb 22 11:23:04.46: [26950]: <-- [9:AT+FRS=7\r]
Feb 22 11:23:04.56: [26950]: --> [2:OK]
Feb 22 11:23:04.56: [26950]: RECV FAX (000000181): from FaxModem1, page 2 in 0:08, INF, 3.85 line/mm, 2-D MMR, 14400 bit/s
Feb 22 11:23:04.56: [26950]: RECV FAX (000000181): recvq/fax000000117.tif from FaxModem1, route to <unspecified>, 2 pages in 0:27
Feb 22 11:23:04.56: [26950]: RECV FAX: Failed to properly detect high-speed data carrier.
Feb 22 11:23:04.56: [26950]: <-- [9:AT+FTH=3\r]
Feb 22 11:23:04.59: [26950]: --> [7:CONNECT]
Feb 22 11:23:05.77: [26950]: --> [2:OK]
Feb 22 11:23:05.77: [26950]: RECV FAX (000000181): session with FaxModem1 terminated abnormally: Failed to properly detect high-speed data carrier.
Feb 22 11:23:05.77: [26950]: RECV FAX: bin/faxrcvd "recvq/fax000000117.tif" "ttyS5" "000000181" "Failed to properly detect high-speed data carrier." "" ""
Feb 22 11:23:05.77: [26950]: RECV FAX: end
Feb 22 11:23:05.77: [26950]: SESSION END

Feb 22 11:22:21.38: [ 7725]: SESSION BEGIN 000000180 ###########
Feb 22 11:22:21.38: [ 7725]: HylaFAX (tm) Version 4.2.1
Feb 22 11:22:21.38: [ 7725]: SEND FAX: JOB 69 DEST ####### COMMID 000000180 DEVICE '/dev/ttyS6'
Feb 22 11:22:21.38: [ 7725]: <-- [12:AT+FCLASS=1\r]
Feb 22 11:22:21.49: [ 7725]: --> [2:OK]
Feb 22 11:22:21.49: [ 7725]: DIAL #######
Feb 22 11:22:21.49: [ 7725]: <-- [12:ATDT#######\r]
Feb 22 11:22:38.11: [ 7725]: --> [7:CONNECT]
Feb 22 11:22:39.82: [ 7725]: --> [2:OK]
Feb 22 11:22:39.82: [ 7725]: REMOTE NSF "B5 00 AA 48 79 6C 61 46 41 58 20 28 74 6D 29 20 56 65 72 73 69 6F 6E 20 34 2E 32 2E 31"
Feb 22 11:22:39.82: [ 7725]: NSF remote fax equipment: HylaFAX
Feb 22 11:22:39.82: [ 7725]: NSF remote station ID: "HylaFAX (tm) Version 4.2.1"
Feb 22 11:22:39.82: [ 7725]: <-- [9:AT+FRH=3\r]
Feb 22 11:22:39.83: [ 7725]: --> [7:CONNECT]
Feb 22 11:22:40.54: [ 7725]: --> [2:OK]
Feb 22 11:22:40.54: [ 7725]: REMOTE CSI "FaxModem1"
Feb 22 11:22:40.54: [ 7725]: <-- [9:AT+FRH=3\r]
Feb 22 11:22:40.55: [ 7725]: --> [7:CONNECT]
Feb 22 11:22:40.94: [ 7725]: --> [2:OK]
Feb 22 11:22:40.94: [ 7725]: REMOTE best rate 14400 bit/s
Feb 22 11:22:40.94: [ 7725]: REMOTE max A3 page width (303 mm)
Feb 22 11:22:40.94: [ 7725]: REMOTE max unlimited page length
Feb 22 11:22:40.94: [ 7725]: REMOTE best vres R16 x 15.4 line/mm
Feb 22 11:22:40.94: [ 7725]: REMOTE best format 2-D MMR
Feb 22 11:22:40.94: [ 7725]: REMOTE supports T.30 Annex A, 256-byte ECM
Feb 22 11:22:40.94: [ 7725]: REMOTE best 0 ms/scanline
Feb 22 11:22:40.94: [ 7725]: USE 14400 bit/s
Feb 22 11:22:40.94: [ 7725]: USE error correction mode
Feb 22 11:22:40.94: [ 7725]: USE 0 ms/scanline
Feb 22 11:22:40.94: [ 7725]: SEND file "docq/doc69.cover;f0"
Feb 22 11:22:40.94: [ 7725]: USE A4 page width (215 mm)
Feb 22 11:22:40.94: [ 7725]: USE unlimited page length
Feb 22 11:22:40.94: [ 7725]: USE 3.85 line/mm
Feb 22 11:22:40.94: [ 7725]: USE 2-D MMR
Feb 22 11:22:40.94: [ 7725]: SEND training at v.17 14400 bit/s
Feb 22 11:22:40.94: [ 7725]: <-- [9:AT+FTH=3\r]
Feb 22 11:22:41.13: [ 7725]: --> [7:CONNECT]
Feb 22 11:22:41.13: [ 7725]: <-- data [23]
Feb 22 11:22:41.13: [ 7725]: <-- data [2]
Feb 22 11:22:41.15: [ 7725]: --> [7:CONNECT]
Feb 22 11:22:41.15: [ 7725]: <-- data [7]
Feb 22 11:22:41.15: [ 7725]: <-- data [2]
Feb 22 11:22:43.13: [ 7725]: --> [2:OK]
Feb 22 11:22:43.13: [ 7725]: <-- [9:AT+FTS=7\r]
Feb 22 11:22:43.21: [ 7725]: --> [2:OK]
Feb 22 11:22:43.21: [ 7725]: <-- [11:AT+FTM=145\r]
Feb 22 11:22:44.69: [ 7725]: --> [7:CONNECT]
Feb 22 11:22:44.69: [ 7725]: <-- data [1024]
Feb 22 11:22:45.00: [ 7725]: <-- data [1024]
Feb 22 11:22:45.33: [ 7725]: <-- data [652]
Feb 22 11:22:45.65: [ 7725]: <-- data [2]
Feb 22 11:22:46.22: [ 7725]: --> [2:OK]
Feb 22 11:22:46.22: [ 7725]: <-- [9:AT+FRS=1\r]
Feb 22 11:22:46.23: [ 7725]: --> [2:OK]
Feb 22 11:22:46.23: [ 7725]: <-- [9:AT+FRH=3\r]
Feb 22 11:22:46.81: [ 7725]: --> [7:CONNECT]
Feb 22 11:22:47.77: [ 7725]: --> [2:OK]
Feb 22 11:22:47.77: [ 7725]: TRAINING succeeded
Feb 22 11:22:47.77: [ 7725]: SEND begin page
Feb 22 11:22:47.78: [ 7725]: SEND EOFB
Feb 22 11:22:47.78: [ 7725]: SEND send frame number 0
Feb 22 11:22:47.78: [ 7725]: SEND send frame number 1
Feb 22 11:22:47.78: [ 7725]: SEND send frame number 2
Feb 22 11:22:47.78: [ 7725]: SEND send frame number 3
Feb 22 11:22:47.78: [ 7725]: SEND send frame number 4
Feb 22 11:22:47.78: [ 7725]: SEND send frame number 5
Feb 22 11:22:47.78: [ 7725]: SEND send frame number 6
Feb 22 11:22:47.78: [ 7725]: SEND send frame number 7
Feb 22 11:22:47.78: [ 7725]: SEND send frame number 8
Feb 22 11:22:47.78: [ 7725]: SEND send frame number 9
Feb 22 11:22:47.78: [ 7725]: SEND send frame number 10
Feb 22 11:22:47.78: [ 7725]: SEND send frame number 11
Feb 22 11:22:47.78: [ 7725]: SEND send frame number 12
Feb 22 11:22:47.78: [ 7725]: SEND send frame number 13
Feb 22 11:22:47.78: [ 7725]: SEND send frame number 14
Feb 22 11:22:47.78: [ 7725]: SEND send frame number 15
Feb 22 11:22:47.78: [ 7725]: DELAY 200 ms
Feb 22 11:22:47.98: [ 7725]: <-- [11:AT+FTM=146\r]
Feb 22 11:22:48.23: [ 7725]: --> [7:CONNECT]
Feb 22 11:22:48.23: [ 7725]: <-- data [1036]
Feb 22 11:22:48.55: [ 7725]: <-- data [1033]
Feb 22 11:22:48.87: [ 7725]: <-- data [1043]
Feb 22 11:22:49.20: [ 7725]: <-- data [1046]
Feb 22 11:22:49.84: [ 7725]: <-- data [608]
Feb 22 11:22:49.84: [ 7725]: <-- data [2]
Feb 22 11:22:50.87: [ 7725]: --> [2:OK]
Feb 22 11:22:50.87: [ 7725]: <-- [9:AT+FTS=7\r]
Feb 22 11:22:50.95: [ 7725]: --> [2:OK]
Feb 22 11:22:50.95: [ 7725]: <-- [9:AT+FTH=3\r]
Feb 22 11:22:51.10: [ 7725]: --> [7:CONNECT]
Feb 22 11:22:51.10: [ 7725]: <-- data [7]
Feb 22 11:22:51.10: [ 7725]: <-- data [2]
Feb 22 11:22:52.38: [ 7725]: --> [2:OK]
Feb 22 11:22:52.38: [ 7725]: SEND send PPS (partial page signal)
Feb 22 11:22:52.38: [ 7725]: SEND send MPS (more pages, same document)
Feb 22 11:22:52.38: [ 7725]: <-- [9:AT+FRH=3\r]
Feb 22 11:22:52.77: [ 7725]: --> [10:NO CARRIER]
Feb 22 11:22:52.77: [ 7725]: MODEM No carrier
Feb 22 11:22:52.77: [ 7725]: <-- [9:AT+FTH=3\r]
Feb 22 11:22:52.96: [ 7725]: --> [7:CONNECT]
Feb 22 11:22:52.96: [ 7725]: <-- data [7]
Feb 22 11:22:52.96: [ 7725]: <-- data [2]
Feb 22 11:22:54.25: [ 7725]: --> [2:OK]
Feb 22 11:22:54.25: [ 7725]: SEND send PPS (partial page signal)
Feb 22 11:22:54.25: [ 7725]: SEND send MPS (more pages, same document)
Feb 22 11:22:54.25: [ 7725]: <-- [9:AT+FRH=3\r]
Feb 22 11:22:54.37: [ 7725]: --> [10:NO CARRIER]
Feb 22 11:22:54.37: [ 7725]: MODEM No carrier
Feb 22 11:22:54.37: [ 7725]: <-- [9:AT+FTH=3\r]
Feb 22 11:22:54.56: [ 7725]: --> [7:CONNECT]
Feb 22 11:22:54.56: [ 7725]: <-- data [7]
Feb 22 11:22:54.56: [ 7725]: <-- data [2]
Feb 22 11:22:55.84: [ 7725]: --> [2:OK]
Feb 22 11:22:55.84: [ 7725]: SEND send PPS (partial page signal)
Feb 22 11:22:55.84: [ 7725]: SEND send MPS (more pages, same document)
Feb 22 11:22:55.84: [ 7725]: <-- [9:AT+FRH=3\r]
Feb 22 11:22:55.97: [ 7725]: --> [10:NO CARRIER]
Feb 22 11:22:55.97: [ 7725]: MODEM No carrier
Feb 22 11:22:55.97: [ 7725]: No response to PPS repeated 3 times.
Feb 22 11:22:55.97: [ 7725]: SEND end page
Feb 22 11:22:55.97: [ 7725]: <-- [9:AT+FTH=3\r]
Feb 22 11:22:56.16: [ 7725]: --> [7:CONNECT]
Feb 22 11:22:56.16: [ 7725]: <-- data [3]
Feb 22 11:22:56.16: [ 7725]: <-- data [2]
Feb 22 11:22:57.34: [ 7725]: --> [2:OK]
Feb 22 11:22:57.34: [ 7725]: <-- [5:ATH0\r]
Feb 22 11:22:57.44: [ 7725]: --> [2:OK]
Feb 22 11:22:57.44: [ 7725]: SESSION END