Subject: kern/3518: uucico fails with -current infernal com driver
To: None <>
From: None <>
List: netbsd-bugs
Date: 04/20/1997 10:30:31
>Number:         3518
>Category:       kern
>Synopsis:       uucico fails on (almost) all incoming transfers
>Confidential:   no
>Severity:       serious
>Priority:       high
>Responsible:    kern-bug-people (Kernel Bug People)
>State:          open
>Class:          sw-bug
>Submitter-Id:   net
>Arrival-Date:   Sun Apr 20 10:05:00 1997
>Originator:     Jim Bernard
	speaking for myself
>Release:        1.2D, Apr 19, 1997
System: NetBSD zoo 1.2D NetBSD 1.2D (ZOO) #0: Sat Apr 19 13:29:01 MDT 1997 local@zoo:/jaz/home/local/compile/sys/arch/i386/compile/ZOO

	  * ASUS P55TP4XE/Pentium 100, ns16550a reported at boot
	  * NCR PCI scsi controller, SCSI and 1 IDE disks installed
	  * Root on wd0 or scsi jaz disk during transfers
	  * 14.4 kbps modem, 38,400 bps DTE speed
	  * uucico is using the "i" protocol, talking to another netbsd
	    host via a terminal server at the other end
	  * data transfer is incoming only (in the cases I've examined)
	  * system running multiuser, but mostly idle during connection

	The basic problem:
	  uucico gets high error rates on incoming transfers, including
	  high numbers of checksum errors, header errors, and order errors,
	  causing transfers to fail almost all the time.  E.g., for ~2 kbyte
	    ERROR: Too many 'i' protocol errors
	    Errors: header 2, checksum 395, order 2, remote rejects 3
	    ERROR: Too many 'i' protocol errors
	    Errors: header 99, checksum 294, order 2, remote rejects 7

	Debugging and other, possibly relevant, info:

	  * When running under a Dec 22 1.2B kernel with -current userland
	    binaries and libraries, all transfers work fine (as they do
	    under a complete Dec 22 1.2B system), so the problem is not
	    in the uucico binary nor libc or libgnumalloc.

	  * Examination of uucico debugging logs shows that initial chat
	    and handshaking take place correctly, but that during data
	    transfer there are occasional losses of 3-byte sequences.  In
	    the debug log, these always occur at the beginning of a string
	    of characters (not generally at the beginning of a packet):
            18:34:49.04: fconn_read: Read 8 "\007\011\000\000YPE "
            18:34:49.04: fiwait_for_packet: Need 91 bytes
            18:34:49.09: fconn_read: Read 91 "IHL D.spudC0IHL daemon -CR D.0IHL 0666 ..."
                                              ^ (missing "D.0")
            18:34:49.09: fiprocess_data: Bad checksum; data 2831139682, frame 956764160
            18:34:49.09: finak: Sending NAK 1
            18:34:49.13: fconn_read: Read 10 "\000\004\000\035From t"
            18:34:49.13: fiwait_for_packet: Need 1022 bytes
            18:34:49.58: fconn_read: Read 1026 "r.Mines.EDU!jbernard  Sat Apr 19 18:21:10 1997\nReceived:..."
                                                ^ (missing "ate")
            18:34:49.58: fiprocess_data: Bad checksum; data 3649475813, frame 119603203
            18:34:49.58: finak: Sending NAK 3
            18:34:49.58: fiwait_for_packet: Need 1016 bytes
            18:34:50.03: fconn_read: Read 1021 "3; Sat, 19 Apr 1997 20:19:28 -0400 (EDT)\nDate:..."
                                                ^ (missing ?)
            18:34:50.03: fiprocess_data: Bad checksum; data 1595943389, frame 593901063
            18:34:50.03: finak: Sending NAK 4
            18:34:50.03: fiprocess_data: Saving unexpected packet 6 (recseq 0)
            18:34:50.03: fiwait_for_packet: Need 5 bytes
            18:34:50.03: fconn_read: Read 8 "YXE D.0I"
                                             ^ (missing 2-4 of packet header--3 bytes total)
            18:34:50.03: fiprocess_data: Bad header
            18:34:50.06: fconn_read: Read 8 "I39\007\031\010\004\000"
            18:34:50.06: fiwait_for_packet: Need 1 bytes
            18:34:50.06: fconn_read: Read 8 "om tater"
                                             ^ (missing byte 6 of header and "Fr"--3 bytes total)
            18:34:50.06: fiprocess_data: Bad header

	  * ppp works fine, incoming ftp transfers work flawlessly (as before)

	  * There are several differences in port settings under ppp and
	    uucico, but all these differences are the same under 1.2B (Dec 22)
	    and 1.2D (April 12); for what it's worth, these are the differences:
            uucico       ppp
            ------       ---
            echoctl    -echoctl    If echoctl is set, echo control characters as ^X
            echoke     -echoke     The KILL character shall (shall not) visually erase
                                   the current line from the display, if possible
             ---        ppp disc
            ixany      -ixany      Allow any character (allow only START) to restart output
           -ignbrk      ignbrk     Ignore (do not ignore) break on input
           -ignpar      ignpar     Ignore (do not ignore) parity errors
            onlcr      -onlcr      Map (do not map) NL to CR-NL on output
            oxtabs     -oxtabs     Expand (do not expand) tabs to spaces on output
            min = 127   min = 1
            time = 1    time = 0

	  * For completeness, here is full output from stty -a:
            during uucico:
              speed 38400 baud; 0 rows; 0 columns;
              lflags: -icanon -isig -iexten -echo -echoe -echok echoke -echonl echoctl
                      -echoprt -altwerase -noflsh -tostop -flusho -pendin -nokerninfo
              iflags: -istrip -icrnl -inlcr -igncr -ixon -ixoff ixany -imaxbel -ignbrk
                      -brkint -inpck -ignpar -parmrk
              oflags: -opost onlcr -ocrnl oxtabs
              cflags: cread cs8 -parenb -parodd hupcl -clocal -cstopb crtscts -mdmbuf
              cchars: discard = ^O; dsusp = ^Y; eof = ^D; eol = <undef>;
                      eol2 = <undef>; erase = ^?; intr = ^C; kill = ^U; lnext = ^V;
                      min = 127; quit = ^\; reprint = ^R; start = ^Q; status = <undef>;
                      stop = ^S; susp = ^Z; time = 1; werase = ^W;
            During ppp:
              ppp disc; speed 38400 baud; 0 rows; 0 columns;
              lflags: -icanon -isig -iexten -echo -echoe -echok -echoke -echonl
                      -echoctl -echoprt -altwerase -noflsh -tostop -flusho -pendin
                      -nokerninfo -extproc
              iflags: -istrip -icrnl -inlcr -igncr -ixon -ixoff -ixany -imaxbel ignbrk
                      -brkint -inpck ignpar -parmrk
              oflags: -opost -onlcr -ocrnl -oxtabs
              cflags: cread cs8 -parenb -parodd hupcl -clocal -cstopb crtscts -mdmbuf
              cchars: discard = ^O; dsusp = ^Y; eof = ^D; eol = <undef>;
                      eol2 = <undef>; erase = ^?; intr = ^C; kill = ^U; lnext = ^V;
                      min = 1; quit = ^\; reprint = ^R; start = ^Q; status = <undef>;
                      stop = ^S; susp = ^Z; time = 0; werase = ^W;

	  * During incoming ftp transfers, the system seems noticeably less
	    responsive than when such transfers are not in progress--this is
	    in sharp contrast to prior versions (specifically Dec 22 1.2B and
	    earlier), for which there is no noticeable degradation in interactive
	    response during incoming ftp transfers.

	Try to receive mail via uucp.
	I suspect that "infernal com driver" (which always worked perfectly
	for me before), which was last updated April 5, but I have no fix.