Koozali.org: home of the SME Server

Diald Errors

Dean Mumby

Diald Errors
« on: March 13, 2002, 11:50:17 AM »
Hi

I have a client who dials up to his isp with an external usr isdn ta the dialup works most of th etime but i get intermitent failures i am including some entrys from the logs

Mar  8 17:30:07 tech-gsm diald[824]: New addresses: local 196.22.188.244, remote 196.22.160.105, broadcast 0.0.0.0
Mar  8 17:31:46 tech-gsm e-smith[26592]: Processing event: ip-up ppp0 /dev/ttyS0 115200 196.22.188.244 196.22.160.105 diald
Mar  8 17:35:07 tech-gsm diald[824]: Failed to received first packet within 300 seconds. Closing Link down.
Mar  8 17:35:09 tech-gsm e-smith[26633]: Processing event: ip-down ppp0 /dev/ttyS0 115200 196.22.188.244 196.22.160.105 diald
Mar  8 17:35:13 tech-gsm diald[824]: Disconnected. Call duration 310 seconds.
Mar  8 17:35:13 tech-gsm diald[824]: IP transmitted 0 bytes and received 0 bytes.
Mar  8 17:35:14 tech-gsm diald[824]: Delaying 10 seconds before clear to dial.
Mar  8 18:30:00 tech-gsm diald[824]: SIGUSR1. External link up request received.
Mar  8 18:30:00 tech-gsm diald[824]: Calling site 196.22.160.105
Mar  8 18:30:03 tech-gsm diald[824]: connector: chat:  Mar 08 18:30:03 CONNECT 64000/ARQ/DIGITAL/X75
Mar  8 18:30:03 tech-gsm diald[824]: Connected to site 196.22.160.105
Mar  8 18:30:03 tech-gsm diald[824]: Running pppd (pid = 27162).
Mar  8 18:30:03 tech-gsm diald[27162]: Running pppd: /usr/sbin/pppd -defaultroute -detach modem crtscts mtu 1500 mru 1500 name grinaker noauth

noipdefault ipparam diald
Mar  8 18:30:07 tech-gsm diald[824]: New addresses: local 196.22.188.179, remote 196.22.160.104, broadcast 0.0.0.0
Mar  8 18:31:41 tech-gsm e-smith[27413]: Processing event: ip-up ppp0 /dev/ttyS0 115200 196.22.188.179 196.22.160.104 diald
Mar  8 18:35:07 tech-gsm diald[824]: Failed to received first packet within 300 seconds. Closing Link down.
Mar  8 18:35:08 tech-gsm e-smith[27443]: Processing event: ip-down ppp0 /dev/ttyS0 115200 196.22.188.179 196.22.160.104 diald
Mar  8 18:35:12 tech-gsm diald[824]: Disconnected. Call duration 309 seconds.
Mar  8 18:35:12 tech-gsm diald[824]: IP transmitted 0 bytes and received 0 bytes.
Mar  8 18:35:14 tech-gsm diald[824]: Delaying 10 seconds before clear to dial.
Mar  8 19:30:00 tech-gsm diald[824]: SIGUSR1. External link up request received.
Mar  8 19:30:00 tech-gsm diald[824]: Calling site 196.22.160.102
Mar  8 19:30:03 tech-gsm diald[824]: connector: chat:  Mar 08 19:30:03 CONNECT 64000/ARQ/DIGITAL/X75
Mar  8 19:30:03 tech-gsm diald[824]: Connected to site 196.22.160.102
Mar  8 19:30:03 tech-gsm diald[27948]: Running pppd: /usr/sbin/pppd -defaultroute -detach modem crtscts mtu 1500 mru 1500 name grinaker noauth

noipdefault ipparam diald
Mar  8 19:30:04 tech-gsm diald[824]: Running pppd (pid = 27948).
Mar  8 19:30:07 tech-gsm diald[824]: New addresses: local 196.22.188.226, remote 196.22.160.105, broadcast 0.0.0.0
Mar  8 19:31:46 tech-gsm e-smith[28186]: Processing event: ip-up ppp0 /dev/ttyS0 115200 196.22.188.226 196.22.160.105 diald
Mar  8 19:35:07 tech-gsm diald[824]: Failed to received first packet within 300 seconds. Closing Link down.
Mar  8 19:35:09 tech-gsm e-smith[28229]: Processing event: ip-down ppp0 /dev/ttyS0 115200 196.22.188.226 196.22.160.105 diald
Mar  8 19:35:13 tech-gsm diald[824]: Disconnected. Call duration 310 seconds.
Mar  8 19:35:13 tech-gsm diald[824]: IP transmitted 0 bytes and received 0 bytes.
Mar  8 19:35:14 tech-gsm diald[824]: Delaying 10 seconds before clear to dial.
Mar  8 20:30:00 tech-gsm diald[824]: SIGUSR1. External link up request received.
Mar  8 20:30:00 tech-gsm diald[824]: Calling site 196.22.160.102
Mar  8 20:30:03 tech-gsm diald[824]: connector: chat:  Mar 08 20:30:03 CONNECT 64000/ARQ/DIGITAL/X75
Mar  8 20:30:03 tech-gsm diald[824]: Connected to site 196.22.160.102
Mar  8 20:30:03 tech-gsm diald[28732]: Running pppd: /usr/sbin/pppd -defaultroute -detach modem crtscts mtu 1500 mru 1500 name grinaker noauth

noipdefault ipparam diald
Mar  8 20:30:03 tech-gsm diald[824]: Running pppd (pid = 28732).
Mar  8 20:30:08 tech-gsm diald[824]: New addresses: local 196.22.188.219, remote 196.22.160.105, broadcast 0.0.0.0
Mar  8 20:31:47 tech-gsm e-smith[28976]: Processing event: ip-up ppp0 /dev/ttyS0 115200 196.22.188.219 196.22.160.105 diald
Mar  8 20:35:08 tech-gsm diald[824]: Failed to received first packet within 300 seconds. Closing Link down.
Mar  8 20:35:09 tech-gsm e-smith[29016]: Processing event: ip-down ppp0 /dev/ttyS0 115200 196.22.188.219 196.22.160.105 diald
Mar  8 20:35:13 tech-gsm diald[824]: Disconnected. Call duration 310 seconds.
Mar  8 20:35:13 tech-gsm diald[824]: IP transmitted 0 bytes and received 0 bytes.
Mar  8 20:35:14 tech-gsm diald[824]: Delaying 10 seconds before clear to dial.
Mar  9 00:00:01 tech-gsm diald[824]: SIGUSR1. External link up request received.
Mar  9 00:00:01 tech-gsm diald[824]: Calling site 196.22.160.104
Mar  9 00:00:04 tech-gsm diald[824]: connector: chat:  Mar 09 00:00:04 CONNECT 64000/ARQ/DIGITAL/X75
Mar  9 00:00:04 tech-gsm diald[824]: Connected to site 196.22.160.104
Mar  9 00:00:04 tech-gsm diald[30673]: Running pppd: /usr/sbin/pppd -defaultroute -detach modem crtscts mtu 1500 mru 1500 name grinaker noauth

noipdefault ipparam diald
Mar  9 00:00:04 tech-gsm diald[824]: Running pppd (pid = 30673).
Mar  9 00:00:08 tech-gsm diald[824]: New addresses: local 196.22.188.180, remote 196.22.160.104, broadcast 0.0.0.0
Mar  9 00:01:47 tech-gsm e-smith[30915]: Processing event: ip-up ppp0 /dev/ttyS0 115200 196.22.188.180 196.22.160.104 diald
Mar  9 00:05:08 tech-gsm diald[824]: Failed to received first packet within 300 seconds. Closing Link down.
Mar  9 00:05:09 tech-gsm e-smith[30958]: Processing event: ip-down ppp0 /dev/ttyS0 115200 196.22.188.180 196.22.160.104 diald
Mar  9 00:05:13 tech-gsm diald[824]: Disconnected. Call duration 309 seconds.
Mar  9 00:05:13 tech-gsm diald[824]: IP transmitted 0 bytes and received 0 bytes.
Mar  9 00:05:14 tech-gsm diald[824]: Delaying 10 seconds before clear to dial.
Mar  9 02:00:00 tech-gsm diald[824]: SIGUSR1. External link up request received.
Mar  9 02:00:00 tech-gsm diald[824]: Calling site 196.22.160.104
Mar  9 02:00:03 tech-gsm diald[824]: connector: chat:  Mar 09 02:00:03 CONNECT 64000/ARQ/DIGITAL/X75
Mar  9 02:00:03 tech-gsm diald[824]: Connected to site 196.22.160.104
Mar  9 02:00:03 tech-gsm diald[824]: Running pppd (pid = 31336).
Mar  9 02:00:03 tech-gsm diald[31336]: Running pppd: /usr/sbin/pppd -defaultroute -detach modem crtscts mtu 1500 mru 1500 name grinaker noauth

noipdefault ipparam diald
Mar  9 02:00:07 tech-gsm diald[824]: New addresses: local 196.22.188.48, remote 196.22.160.102, broadcast 0.0.0.0
Mar  9 02:01:45 tech-gsm e-smith[31577]: Processing event: ip-up ppp0 /dev/ttyS0 115200 196.22.188.48 196.22.160.102 diald
Mar  9 02:05:07 tech-gsm diald[824]: Failed to received first packet within 300 seconds. Closing Link down.
Mar  9 02:05:08 tech-gsm e-smith[31619]: Processing event: ip-down ppp0 /dev/ttyS0 115200 196.22.188.48 196.22.160.102 diald
Mar  9 02:05:13 tech-gsm diald[824]: Disconnected. Call duration 310 seconds.
Mar  9 02:05:13 tech-gsm diald[824]: IP transmitted 0 bytes and received 0 bytes.
Mar  9 02:05:14 tech-gsm diald[824]: Delaying 10 seconds before clear to dial.
Mar  9 02:09:24 tech-gsm diald[824]: Trigger: udp          10.0.0.1/1025      196.22.160.5/53  
Mar  9 02:09:24 tech-gsm diald[824]: Calling site 196.22.160.102
Mar  9 02:09:27 tech-gsm diald[824]: connector: chat:  Mar 09 02:09:27 CONNECT 64000/ARQ/DIGITAL/X75
Mar  9 02:09:27 tech-gsm diald[824]: Connected to site 196.22.160.102
Mar  9 02:09:28 tech-gsm diald[31646]: Running pppd: /usr/sbin/pppd -defaultroute -detach modem crtscts mtu 1500 mru 1500 name grinaker noauth

noipdefault ipparam diald
Mar  9 02:09:27 tech-gsm diald[824]: Running pppd (pid = 31646).
Mar  9 02:09:31 tech-gsm diald[824]: New addresses: local 196.22.188.152, remote 196.22.160.104, broadcast 0.0.0.0
Mar  9 02:10:06 tech-gsm diald[824]: Closing down idle link.
Mar  9 02:11:06 tech-gsm diald[824]: child process 31646 terminated with signal 9
Mar  9 02:11:07 tech-gsm diald[824]: Disconnected. Call duration 100 seconds.
Mar  9 02:11:07 tech-gsm diald[824]: IP transmitted 134 bytes and received 122 bytes.
Mar  9 02:11:08 tech-gsm diald[824]: Delaying 10 seconds before clear to dial.
Mar  9 02:11:08 tech-gsm e-smith[31903]: Processing event: ip-up ppp0 /dev/ttyS0 115200 196.22.188.152 196.22.160.104 diald
Mar  9 02:56:44 tech-gsm diald[824]: Trigger: udp          10.0.0.1/1025      196.22.160.5/53  
Mar  9 02:56:44 tech-gsm diald[824]: Calling site 196.22.160.104
Mar  9 02:56:47 tech-gsm diald[824]: connector: chat:  Mar 09 02:56:47 CONNECT 64000/ARQ/DIGITAL/X75
Mar  9 02:56:47 tech-gsm diald[824]: Connected to site 196.22.160.104
Mar  9 02:56:47 tech-gsm diald[824]: Running pppd (pid = 32066).
Mar  9 02:56:47 tech-gsm diald[32066]: Running pppd: /usr/sbin/pppd -defaultroute -detach modem crtscts mtu 1500 mru 1500 name grinaker noauth

noipdefault ipparam diald
Mar  9 02:56:51 tech-gsm diald[824]: New addresses: local 196.22.189.12, remote 196.22.160.106, broadcast 0.0.0.0
Mar  9 02:57:29 tech-gsm diald[824]: Closing down idle link.
Mar  9 02:58:23 tech-gsm e-smith[32324]: Processing event: ip-up ppp0 /dev/ttyS0 115200 196.22.189.12 196.22.160.106 diald
Mar  9 02:58:29 tech-gsm diald[824]: child process 32066 terminated with signal 9
Mar  9 02:58:30 tech-gsm diald[824]: Disconnected. Call duration 103 seconds.
Mar  9 02:58:30 tech-gsm diald[824]: IP transmitted 287 bytes and received 797 bytes.
Mar  9 02:58:31 tech-gsm diald[824]: Delaying 10 seconds before clear to dial.
Mar  9 04:00:00 tech-gsm diald[824]: SIGUSR1. External link up request received.
Mar  9 04:00:00 tech-gsm diald[824]: Calling site 196.22.160.106
Mar  9 04:00:03 tech-gsm diald[824]: connector: chat:  Mar 09 04:00:03 CONNECT 64000/ARQ/DIGITAL/X75
Mar  9 04:00:03 tech-gsm diald[824]: Connected to site 196.22.160.106
Mar  9 04:00:03 tech-gsm diald[824]: Running pppd (pid = 32547).
Mar  9 04:00:03 tech-gsm diald[32547]: Running pppd: /usr/sbin/pppd -defaultroute -detach modem crtscts mtu 1500 mru 1500 name grinaker noauth

noipdefault ipparam diald
Mar  9 04:00:07 tech-gsm diald[824]: New addresses: local 196.22.189.4, remote 196.22.160.106, broadcast 0.0.0.0
Mar  9 04:01:45 tech-gsm e-smith[322]: Processing event: ip-up ppp0 /dev/ttyS0 115200 196.22.189.4 196.22.160.106 diald
Mar  9 04:05:07 tech-gsm diald[824]: Failed to received first packet within 300 seconds. Closing Link down.
Mar  9 04:05:09 tech-gsm e-smith[383]: Processing event: ip-down ppp0 /dev/ttyS0 115200 196.22.189.4 196.22.160.106 diald
Mar  9 04:05:13 tech-gsm diald[824]: Disconnected. Call duration 310 seconds.
Mar  9 04:05:13 tech-gsm diald[824]: IP transmitted 0 bytes and received 0 bytes.
Mar  9 04:05:14 tech-gsm diald[824]: Delaying 10 seconds before clear to dial.
Mar  9 06:00:00 tech-gsm diald[824]: SIGUSR1. External link up request received.
Mar  9 06:00:00 tech-gsm diald[824]: Calling site 196.22.160.106
Mar  9 06:00:03 tech-gsm diald[824]: connector: chat:  Mar 09 06:00:03 CONNECT 64000/ARQ/DIGITAL/X75
Mar  9 06:00:03 tech-gsm diald[824]: Connected to site 196.22.160.106
Mar  9 06:00:03 tech-gsm diald[1042]: Running pppd: /usr/sbin/pppd -defaultroute -detach modem crtscts mtu 1500 mru 1500 name grinaker noauth

noipdefault ipparam diald
Mar  9 06:00:03 tech-gsm diald[824]: Running pppd (pid = 1042).
Mar  9 06:00:07 tech-gsm diald[824]: New addresses: local 196.22.188.21, remote 196.22.160.102, broadcast 0.0.0.0
Mar  9 06:01:42 tech-gsm e-smith[1302]: Processing event: ip-up ppp0 /dev/ttyS0 115200 196.22.188.21 196.22.160.102 diald
Mar  9 06:05:07 tech-gsm diald[824]: Failed to received first packet within 300 seconds. Closing Link down.
Mar  9 06:05:08 tech-gsm e-smith[1331]: Processing event: ip-down ppp0 /dev/ttyS0 115200 196.22.188.21 196.22.160.102 diald
Mar  9 06:05:13 tech-gsm diald[824]: Disconnected. Call duration 310 seconds.
Mar  9 06:05:13 tech-gsm diald[824]: IP transmitted 0 bytes and received 0 bytes.
Mar  9 06:05:14 tech-gsm diald[824]: Delaying 10 seconds before clear to dial.
Mar  9 08:00:00 tech-gsm diald[824]: SIGUSR1. External link up request received.
Mar  9 08:00:00 tech-gsm diald[824]: Calling site 196.22.160.102
Mar  9 08:00:03 tech-gsm diald[824]: connector: chat:  Mar 09 08:00:03 CONNECT 64000/ARQ/DIGITAL/X75
Mar  9 08:00:03 tech-gsm diald[824]: Connected to site 196.22.160.102
Mar  9 08:00:03 tech-gsm diald[824]: Running pppd (pid = 1726).
Mar  9 08:00:03 tech-gsm diald[1726]: Running pppd: /usr/sbin/pppd -defaultroute -detach modem crtscts mtu 1500 mru 1500 name grinaker noauth

noipdefault ipparam diald
Mar  9 08:00:07 tech-gsm diald[824]: New addresses: local 196.22.188.148, remote 196.22.160.104, broadcast 0.0.0.0
Mar  9 08:01:41 tech-gsm e-smith[1980]: Processing event: ip-up ppp0 /dev/ttyS0 115200 196.22.188.148 196.22.160.104 diald
Mar  9 08:05:07 tech-gsm diald[824]: Failed to received first packet within 300 seconds. Closing Link down.
Mar  9 08:05:09 tech-gsm e-smith[2010]: Processing event: ip-down ppp0 /dev/ttyS0 115200 196.22.188.148 196.22.160.104 diald
Mar  9 08:05:13 tech-gsm diald[824]: Disconnected. Call duration 310 seconds.
Mar  9 08:05:13 tech-gsm diald[824]: IP transmitted 0 bytes and received 0 bytes.
Mar  9 08:05:14 tech-gsm diald[824]: Delaying 10 seconds before clear to dial.
Mar  9 08:10:04 tech-gsm diald[824]: Trigger: udp          10.0.0.1/1025      196.22.160.5/53  
Mar  9 08:10:04 tech-gsm diald[824]: Calling site 196.22.160.104
Mar  9 08:10:07 tech-gsm diald[824]: connector: chat:  Mar 09 08:10:07 CONNECT 64000/ARQ/DIGITAL/X75
Mar  9 08:10:07 tech-gsm diald[824]: Connected to site 196.22.160.104
Mar  9 08:10:07 tech-gsm diald[824]: Running pppd (pid = 2035).
Mar  9 08:10:07 tech-gsm diald[2035]: Running pppd: /usr/sbin/pppd -defaultroute -detach modem crtscts mtu 1500 mru 1500 name grinaker noauth

noipdefault ipparam diald
Mar  9 08:10:11 tech-gsm diald[824]: New addresses: local 196.22.189.89, remote 196.22.160.108, broadcast 0.0.0.0
Mar  9 08:10:42 tech-gsm diald[824]: Closing down idle link.
Mar  9 08:11:42 tech-gsm diald[824]: child process 2035 terminated with signal 9
Mar  9 08:11:43 tech-gsm diald[824]: Disconnected. Call duration 96 seconds.
Mar  9 08:11:43 tech-gsm diald[824]: IP transmitted 136 bytes and received 380 bytes.
Mar  9 08:11:44 tech-gsm diald[824]: Delaying 10 seconds before clear to dial.
Mar  9 08:11:49 tech-gsm e-smith[2280]: Processing event: ip-up ppp0 /dev/ttyS0 115200 196.22.189.89 196.22.160.108 diald
Mar  9 08:34:06 tech-gsm diald[824]: Trigger: udp          10.0.0.1/1025      196.22.160.5/53  
Mar  9 08:34:06 tech-gsm diald[824]: Calling site 196.22.160.108
Mar  9 08:34:09 tech-gsm diald[824]: connector: chat:  Mar 09 08:34:09 CONNECT 64000/ARQ/DIGITAL/X75
Mar  9 08:34:09 tech-gsm diald[824]: Connected to site 196.22.160.108
Mar  9 08:34:09 tech-gsm diald[824]: Running pppd (pid = 2382).
Mar  9 08:34:09 tech-gsm diald[2382]: Running pppd: /usr/sbin/pppd -defaultroute -detach modem crtscts mtu 1500 mru 1500 name grinaker noauth

noipdefault ipparam diald
Mar  9 08:34:13 tech-gsm diald[824]: New addresses: local 196.22.189.58, remote 196.22.160.106, broadcast 0.0.0.0
Mar  9 08:35:49 tech-gsm e-smith[2634]: Processing event: ip-up ppp0 /dev/ttyS0 115200 196.22.189.58 196.22.160.106 diald
Mar  9 08:41:35 tech-gsm diald[824]: Closing down idle link.
Mar  9 08:41:36 tech-gsm e-smith[2718]: Processing event: ip-down ppp0 /dev/ttyS0 115200 196.22.189.58 196.22.160.106 diald
Mar  9 08:41:40 tech-gsm diald[824]: Disconnected. Call duration 451 seconds.
Mar  9 08:41:40 tech-gsm diald[824]: IP transmitted 4882 bytes and received 40980 bytes.
Mar  9 08:41:41 tech-gsm diald[824]: Delaying 10 seconds before clear to dial.


My first question is how can i reduce the timeout variable for when this error occurs i.e no packets are recieved.

Second here is a copy of ifconfig ppp0 while the link is up notice how all the errors are on RX does this imply that the fault is with the ISP or is this normal.

ppp0      Link encap:Point-to-Point Protocol  
          inet addr:196.22.188.159  P-t-P:196.22.160.104  Mask:255.255.255.255
          UP POINTOPOINT RUNNING NOARP MULTICAST  MTU:1500  Metric:1
          RX packets:8440 errors:261 dropped:0 overruns:0 frame:261
          TX packets:7330 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:10




Any help / suggestions are very welcome

Thanks
Regards
Dean mumby

Kees Blokland

Re: Diald Errors
« Reply #1 on: March 13, 2002, 03:33:14 PM »
Hi Dean,

Sounds like a typically overloaded ISP to me..

What happens (at least where I live) is that when you dial your ISP, the isdn/modem on the other end answers the call, but that does not mean there is actually a computer ready to talk to you.  (however, since your call gets answered, the phonecompany starts charging you !!)

So, your call is answered by an isdnbox on the remote end, who then tries to tell the ISP's computer there is someone on the line... ISP's Computer System is too busy, and eventually, your side gives up, because there is no-one to talk too..

I know this is a rather simplistic explanation, but you get the idea..

It would not surprise me, if this happens more/less on different times of the day..


good luck

keees