Subject: kern/3518: uucico fails with -current infernal com driver
To: None <gnats-bugs@gnats.netbsd.org>
From: None <jbernard@tater.mines.edu>
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
>Last-Modified:
>Originator:     Jim Bernard
>Organization:
	speaking for myself
>Release:        1.2D, Apr 19, 1997
>Environment:
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


>Description:
	Configuration:
	  * 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
	  transfers:
	    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
                      -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 = 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.

>How-To-Repeat:
	Try to receive mail via uucp.
>Fix:
	I suspect that "infernal com driver" (which always worked perfectly
	for me before), which was last updated April 5, but I have no fix.
>Audit-Trail:
>Unformatted: