pppd - dropped packets, slow, stalls, unable to load certain pages

pppd - dropped packets, slow, stalls, unable to load certain pages

Post by Craig Moffit » Mon, 14 Feb 2000 04:00:00



Greetings friends,

I'm still having problems with my modem connection.  Any help would be
greatly
appreciated.  I've had problems like this for several months and have
bought a new
modem and serial card.  If anyone needs more information or would like
me to run
some sort of test, I'd be more than happy to!

Current Setup
--------------
kernel 2.0.38 on a 486
pppd version 2.2
setserial version 2.14
USR 56k v.90 External Sportster
16C650 UART on a seperate serial card (new, bought to attempt to fix
problem)
init string = AT&F1 ( also tried AT&F1&B1&D2&H1&I0&K1&M4S7=60 )
execute command = exec /usr/sbin/pppd debug /dev/ttyS1 115200 \
        $LOCAL_IP:$REMOTE_IP \
        connect $DIALER_SCRIPT

Typical Performance (try not to cry)
---------------------
ppp0      Link encap:Point-Point Protocol
          inet addr:209.204.109.209  P-t-P:209.204.65.47
Mask:255.255.255.0
          UP POINTOPOINT RUNNING  MTU:1500  Metric:1
          RX packets:433 errors:27 dropped:27 overruns:0
          TX packets:435 errors:0 dropped:0 overruns:0
This is actually better than usual, I average 10% dropped.  The
performance seems to
be better during long downloads as opposed to making a connection.
Some pages are ok, some slow, and some don't ever load (egghead.com for
example)

Other Availible Resources for testing
-------------------------------------
Win 95 P166 with 16550A UART
USR 14.4 External Sportster
16450 UART on multi I/O board

thanks everyone in advance,
Craig

 
 
 

pppd - dropped packets, slow, stalls, unable to load certain pages

Post by Clifford Kit » Wed, 16 Feb 2000 04:00:00



> init string = AT&F1 ( also tried AT&F1&B1&D2&H1&I0&K1&M4S7=60 )
> execute command = exec /usr/sbin/pppd debug /dev/ttyS1 115200 \
>         $LOCAL_IP:$REMOTE_IP \
>         connect $DIALER_SCRIPT

The first thing you can try is to add teh pppd option "crtscts" since
the modem is likely defaulting to hardware flow control.  I'd also
recommend adding the pppd option "asyncmap 0" unless this causes the
PPP negotiations themselves to fail and you get no Internet access.
Using "asyncmap a0000" is the next best thing to "asyncmap 0" and
sometimes cures obscure problems.

You also need to make sure that these pppd option are *all* that are
present, e.g., check the /etc/ppp/options file and any script that
it may call.

Sometimes an IDE drive can keep interrupts off too long in which case
hdparm with the -u1 option might cure the problem.  But read the caution
in the section of the man pages that describes this option.

If these don't help then check/post the PPP link negotiation messages
using the pppd debug option.  Sometimes these can give a clue as to
what might be causing the problem.  The timestamps of the chat -v
messages can help to identify a device file IRQ misconfiguration.

If those things don't bring any joy then add the pppd option "kdebug 2"
to get a hex dump of one or more received frames that contain the errors.
This too can sometimes provide a clue as to what's causing the problem.
If the errors are generated by a ping then use "kdebug 5" and compare
the outgoing frame to the received frame.

--

/* Better is the enemy of good enough. */

 
 
 

pppd - dropped packets, slow, stalls, unable to load certain pages

Post by Craig Moffit » Thu, 17 Feb 2000 04:00:00


thanks for the reply.

asyncmap was already 0 and crtscts was already in use.
I tried "hdparm -u 1 /dev/hdX" for all my drives (but no reboot), didn't fix
the problem.
Attached is the /etc/ppp/options (named options.old before I put in the
kdebug lines) and an except from /var/log/messages, but i'm not sure where
to get that hex dump of packets that you were talking about.

well, at least the hdparm didn't zap the old HDD.  Thoughts, insights and/or
speculations from anyone would be appreciated!

Craig


> The first thing you can try is to add teh pppd option "crtscts" since
> the modem is likely defaulting to hardware flow control.  I'd also
> recommend adding the pppd option "asyncmap 0" unless this causes the
> PPP negotiations themselves to fail and you get no Internet access.
> Using "asyncmap a0000" is the next best thing to "asyncmap 0" and
> sometimes cures obscure problems.

> You also need to make sure that these pppd option are *all* that are
> present, e.g., check the /etc/ppp/options file and any script that
> it may call.

> Sometimes an IDE drive can keep interrupts off too long in which case
> hdparm with the -u1 option might cure the problem.  But read the caution
> in the section of the man pages that describes this option.

> If these don't help then check/post the PPP link negotiation messages
> using the pppd debug option.  Sometimes these can give a clue as to
> what might be causing the problem.
>   The timestamps of the chat -v
> messages can help to identify a device file IRQ misconfiguration.

> If those things don't bring any joy then add the pppd option "kdebug 2"
> to get a hex dump of one or more received frames that contain the errors.
> This too can sometimes provide a clue as to what's causing the problem.
> If the errors are generated by a ping then use "kdebug 5" and compare
> the outgoing frame to the received frame.

> --

> /* Better is the enemy of good enough. */

[ options.old < 1K ]
# /etc/ppp/options
# copied by hand from Linux PPP Howto
#

# Prevent pppd from forking into the background
-detach

#use the modem control lines
#modem

# use uucp style locks to ensure exclusive access to the serial device
lock

#use hardware flow control
crtscts

#create a default route for this connection in the routing table
defaultroute
# CM - removed to attempt to get diald to work

#do NOT set up any "escaped" control sequence
asyncmap 0

#use a maximum transmission packet size of 552 bytes
#2/10/2000 by Xosf -- was mtu 552
mtu 1500

#use a maximum receive packet size of 552 bytes
#mru 552 2/10/2000 by Xosf
mru 1500

#
# -- END OF COPIED FILE

[ ppp_errors 5K ]
Feb 17 06:43:00 crescent pppd[24878]: pppd 2.2.0 started by root, uid 0
Feb 17 06:43:02 crescent chat[24883]: timeout set to 3 seconds
Feb 17 06:43:02 crescent chat[24883]: abort on (\nBUSY\r)
Feb 17 06:43:02 crescent chat[24883]: abort on (\nNO ANSWER\r)
Feb 17 06:43:02 crescent chat[24883]: abort on (\nRINGING\r\n\r\nRINGING\r)
Feb 17 06:43:02 crescent chat[24883]: send (rATZ^M)
Feb 17 06:43:02 crescent chat[24883]: expect (OK)
Feb 17 06:43:02 crescent chat[24883]: rATZ^M^M
Feb 17 06:43:02 crescent chat[24883]: OK -- got it
Feb 17 06:43:02 crescent chat[24883]: send (AT&F1^M)
Feb 17 06:43:02 crescent chat[24883]: timeout set to 30 seconds
Feb 17 06:43:02 crescent chat[24883]: expect (OK)
Feb 17 06:43:02 crescent chat[24883]: ^M
Feb 17 06:43:02 crescent chat[24883]: AT&F1^M^M
Feb 17 06:43:02 crescent chat[24883]: OK -- got it
Feb 17 06:43:02 crescent chat[24883]: send (ATDT325-9902^M)
Feb 17 06:43:02 crescent chat[24883]: expect (CONNECT)
Feb 17 06:43:02 crescent chat[24883]: ^M
Feb 17 06:43:07 crescent login: ROOT LOGIN ON tty6
Feb 17 06:43:21 crescent chat[24883]: ATDT325-9902^M^M
Feb 17 06:43:21 crescent chat[24883]: CONNECT -- got it
Feb 17 06:43:21 crescent chat[24883]: send (^M)
Feb 17 06:43:22 crescent chat[24883]: expect (ogin:)
Feb 17 06:43:22 crescent chat[24883]:  52000/ARQ/V90/LAPM/V42BIS^M
Feb 17 06:43:23 crescent chat[24883]: ^M
Feb 17 06:43:23 crescent chat[24883]: Welcome to 3Com Total Control HiPer ARC (TM)^M
Feb 17 06:43:23 crescent chat[24883]: Networks That Go The Distance (TM)^M
Feb 17 06:43:23 crescent chat[24883]: ^M
Feb 17 06:43:23 crescent chat[24883]: login: -- got it
Feb 17 06:43:23 crescent chat[24883]: send (XXXXXXX^M)
Feb 17 06:43:23 crescent pppd[24878]: Serial connection established.
Feb 17 06:43:23 crescent chat[24883]: expect (assword:)
Feb 17 06:43:23 crescent chat[24883]:  cmoffitt^M
Feb 17 06:43:23 crescent chat[24883]: Password: -- got it
Feb 17 06:43:23 crescent chat[24883]: send (XXXXXX^M)
Feb 17 06:43:24 crescent pppd[24878]: Using interface ppp0
Feb 17 06:43:24 crescent pppd[24878]: Connect: ppp0 <--> /dev/ttyS1
Feb 17 06:43:24 crescent kernel: ppp_tty_ioctl: set flags to 30000
Feb 17 06:43:25 crescent kernel: ppp_tty_ioctl: set flags to 30000
Feb 17 06:43:25 crescent kernel: ppp_tty_ioctl: set xasyncmap
Feb 17 06:43:25 crescent kernel: ppp_tty_ioctl: set xmit asyncmap ffffffff
Feb 17 06:43:25 crescent kernel: ppp_tty_ioctl: set flags to 30000
Feb 17 06:43:25 crescent kernel: ppp_tty_ioctl: set mru to 5dc
Feb 17 06:43:25 crescent kernel: ppp_tty_ioctl: set rcv asyncmap 0
Feb 17 06:43:25 crescent kernel: ppp_tty_ioctl: set flags to 30010
Feb 17 06:43:25 crescent kernel: ppp: successfully queued 12 bytes, flags = f030010
Feb 17 06:43:25 crescent kernel: ppp: successfully queued 26 bytes, flags = f030010
Feb 17 06:43:26 crescent kernel: ppp: successfully queued 33 bytes, flags = f030010
Feb 17 06:43:26 crescent kernel: ppp: successfully queued 26 bytes, flags = f030010
Feb 17 06:43:26 crescent kernel: ppp_tty_ioctl: set xmit asyncmap ffffffff
Feb 17 06:43:26 crescent kernel: ppp_tty_ioctl: set flags to f030013
Feb 17 06:43:26 crescent kernel: ppp_tty_ioctl: set mru to 5dc
Feb 17 06:43:26 crescent kernel: ppp_tty_ioctl: set rcv asyncmap ffffffff
Feb 17 06:43:26 crescent kernel: ppp_tty_ioctl: set flags to f030003
Feb 17 06:43:26 crescent kernel: ppp_tty_ioctl: set flags to f030043
Feb 17 06:43:27 crescent kernel: ppp: successfully queued 18 bytes, flags = f030043
Feb 17 06:43:27 crescent kernel: ppp: frame with bad fcs, excess = 2fc
Feb 17 06:43:27 crescent kernel: ppp: successfully queued 15 bytes, flags = f030043
Feb 17 06:43:27 crescent kernel: ppp_tty_ioctl: set flags to f030003
Feb 17 06:43:30 crescent kernel: ppp: successfully queued 18 bytes, flags = f030003
Feb 17 06:43:30 crescent pppd[24878]: local  IP address 209.204.78.219
Feb 17 06:43:30 crescent pppd[24878]: remote IP address 209.204.65.44
Feb 17 06:43:30 crescent kernel: ppp: successfully queued 18 bytes, flags = f030003
Feb 17 06:43:30 crescent kernel: ppp_tty_ioctl: set maxcid to 16
Feb 17 06:43:30 crescent kernel: ppp_tty_ioctl: set flags to f03000f
Feb 17 06:43:30 crescent kernel: ppp: channel ppp0 going up for IP packets!
Feb 17 06:44:02 crescent kernel: ppp: frame with bad fcs, excess = 36a3
Feb 17 06:44:02 crescent kernel: ppp: frame with bad fcs, excess = 1e20
Feb 17 06:44:02 crescent kernel: ppp: frame with bad fcs, excess = 1b38
Feb 17 06:44:13 crescent kernel: ppp: frame with bad fcs, excess = a0ad
Feb 17 06:44:14 crescent kernel: ppp: frame with bad fcs, excess = e63f
Feb 17 06:44:27 crescent kernel: ppp: channel ppp0 going down for IP packets!
Feb 17 06:44:27 crescent kernel: ppp_tty_ioctl: set xmit asyncmap ffffffff
Feb 17 06:44:27 crescent kernel: ppp_tty_ioctl: set flags to f03000c
Feb 17 06:44:27 crescent kernel: ppp_tty_ioctl: set mru to 5dc
Feb 17 06:44:27 crescent kernel: ppp_tty_ioctl: set rcv asyncmap 0
Feb 17 06:44:27 crescent kernel: ppp_tty_ioctl: set flags to f03001c
Feb 17 06:44:27 crescent kernel: ppp_tty_ioctl: set flags to f03001c
Feb 17 06:44:27 crescent pppd[24878]: Terminating on signal 2.
Feb 17 06:44:27 crescent pppd[24878]: Connection terminated.
Feb 17 06:44:27 crescent pppd[24878]: Exit.
Feb 17 06:44:27 crescent kernel: ppp: successfully queued 6 bytes, flags = f03001c
Feb 17 06:44:27 crescent kernel: ppp_tty_ioctl: get debug level 3
Feb 17 06:44:27 crescent kernel: ppp_tty_ioctl: set flags to f00001c

 
 
 

pppd - dropped packets, slow, stalls, unable to load certain pages

Post by Bill Unr » Sat, 19 Feb 2000 04:00:00



]thanks for the reply.

]asyncmap was already 0 and crtscts was already in use.

Try
asyncmap a0000

Put in a
debug
line into /etc/ppp/options.
Then put
daemon.*                        /var/log/messages
into /etc/syslog.conf
and do
killall -1 syslogd

Then try again and post.
Also are you sure you should be using logon authentication?

]Feb 17 06:43:02 crescent chat[24883]: send (rATZ^M)
]Feb 17 06:43:02 crescent chat[24883]: expect (OK)
]Feb 17 06:43:02 crescent chat[24883]: rATZ^M^M
]Feb 17 06:43:02 crescent chat[24883]: OK -- got it
]Feb 17 06:43:02 crescent chat[24883]: send (AT&F1^M)
]Feb 17 06:43:02 crescent chat[24883]: timeout set to 30 seconds
]Feb 17 06:43:02 crescent chat[24883]: expect (OK)
]Feb 17 06:43:02 crescent chat[24883]: ^M
]Feb 17 06:43:02 crescent chat[24883]: AT&F1^M^M
]Feb 17 06:43:02 crescent chat[24883]: OK -- got it

No IRQ problem here.

 
 
 

pppd - dropped packets, slow, stalls, unable to load certain pages

Post by Craig Moffit » Sat, 19 Feb 2000 04:00:00


hi.

more updates.

1) it still drops a large percentage of packets

2) ping doesn't drop packets (or at least not after the fixes i've already
applied), I managed to get off several hundred in a row.

3) for some reason I was able to go to some of the web sites previously
unreachable.

my guess is that the hdparm made to computer more tolerant of the error, but
it didn't fix the underlying problem.

Craig

 
 
 

pppd - dropped packets, slow, stalls, unable to load certain pages

Post by Craig Moffit » Sun, 27 Feb 2000 04:00:00


Clifford and Bill,

thanks for the help.

Quote:> That was my fault, I have trouble with arithmetic sometimes, the kdebug
> value for both transmitted and receive hex dumps should be 4+2 = 6,
> kdebug 6.  It looks like the hex dump output isn't provided by pppd
> 2.2.0 either, that's an old version - but pppd 2.2.0 certainly worked
> fine with the 2.0.38 kernel for me.

hmmm.. even tried kdebug 7 after setting up as per Bill in the syslog.conf and
didn't get hex output anywhere.

Quote:

> Check the UART type configured for the device file when you look at
> the setserial output, is it a 16650?

yup!

Quote:

> The pppd debug output for PPP link negotiation doesn't appear in
> the pppd log, did you use the "debug" option?  That output may be
> in another log.  Bill Unruh's suggestion will put everything into
> /var/log/messages.  The IP addresses were apparently successfully
> negotiated but the PPP link negotiation messages can sometimes point
> to a PPP implementation problem at the ISP and suggest a solution.

> Trying the "asyncmap a0000" option is easy, and even if it failed it
> would eliminate one potential source of the problem.

tried it briefly and I dropped 3 out of the first 20 packets.

ok.  I'm going to try to switch distros and upgrade my versions of everything.
perhaps a bit exteremen, but what the heck.

Craig

 
 
 

pppd - dropped packets, slow, stalls, unable to load certain pages

Post by Craig Moffit » Mon, 28 Feb 2000 04:00:00


hi,

a wierd thing happened last night.
I was able to see some hex packets by typing "dmesg" but it didn't have
everything, and I wasn't able to find any file with the complete info.

This seems to be some kind of logging problem.  This happened with
kdebug 7,   in /etc/ppp/options and
daemon.*       /var/log/daemonlog.

I couldn't find a syslog HOWTO, any idea what happened or how I can get that hex
info?

thanks in advance!
Craig