* Re: some change in ppp 2.4.3: tcflush failed: Bad file descriptor
2004-11-23 10:57 some change in ppp 2.4.3: tcflush failed: Bad file descriptor Arkadiusz Miskiewicz
@ 2004-11-23 16:06 ` James Carlson
2004-11-25 15:44 ` Arkadiusz Miskiewicz
` (4 subsequent siblings)
5 siblings, 0 replies; 7+ messages in thread
From: James Carlson @ 2004-11-23 16:06 UTC (permalink / raw)
To: linux-ppp
Arkadiusz Miskiewicz writes:
> Nov 18 16:00:25 arm pppd[17641]: Using interface ppp0
> Nov 18 16:00:25 arm pppd[17641]: Connect: ppp0 <--> /dev/pts/12
> Nov 18 16:00:56 arm pppd[17641]: LCP terminated by peer
> Nov 18 16:00:59 arm pppd[17641]: Connection terminated.
Try running with debug enabled. The 'LCP terminated by peer' message
indicates that something went wrong when trying to negotiate with the
peer system. Perhaps there's an authentication problem.
> With 2.4.2 there was no problem with ,,tcflush failed: Bad file descriptor''
> on the same kernel.
I've seen it before, but I don't think it's actually harmful.
--
James Carlson <carlsonj@workingcode.com>
^ permalink raw reply [flat|nested] 7+ messages in thread* Re: some change in ppp 2.4.3: tcflush failed: Bad file descriptor
2004-11-23 10:57 some change in ppp 2.4.3: tcflush failed: Bad file descriptor Arkadiusz Miskiewicz
2004-11-23 16:06 ` James Carlson
@ 2004-11-25 15:44 ` Arkadiusz Miskiewicz
2004-11-25 16:09 ` Arkadiusz Miskiewicz
` (3 subsequent siblings)
5 siblings, 0 replies; 7+ messages in thread
From: Arkadiusz Miskiewicz @ 2004-11-25 15:44 UTC (permalink / raw)
To: linux-ppp
On Tuesday 23 of November 2004 17:06, James Carlson wrote:
> Arkadiusz Miskiewicz writes:
> > Nov 18 16:00:25 arm pppd[17641]: Using interface ppp0
> > Nov 18 16:00:25 arm pppd[17641]: Connect: ppp0 <--> /dev/pts/12
> > Nov 18 16:00:56 arm pppd[17641]: LCP terminated by peer
> > Nov 18 16:00:59 arm pppd[17641]: Connection terminated.
>
> Try running with debug enabled. The 'LCP terminated by peer' message
> indicates that something went wrong when trying to negotiate with the
> peer system. Perhaps there's an authentication problem.
Nov 24 12:19:10 arm pppd[5447]: Connect: ppp0 <--> /dev/pts/65
Nov 24 12:19:11 arm pppd[5447]: sent [LCP ConfReq id=0x3c <asyncmap 0x0> <magic 0xf68ca3b4> <pcomp> <accomp>]
Nov 24 12:19:14 arm pppd[5447]: sent [LCP ConfReq id=0x3c <asyncmap 0x0> <magic 0xf68ca3b4> <pcomp> <accomp>]
Nov 24 12:19:18 arm pppd[5447]: sent [LCP ConfReq id=0x3c <asyncmap 0x0> <magic 0xf68ca3b4> <pcomp> <accomp>]
Nov 24 12:19:21 arm pppd[5447]: sent [LCP ConfReq id=0x3c <asyncmap 0x0> <magic 0xf68ca3b4> <pcomp> <accomp>]
Nov 24 12:19:25 arm pppd[5447]: sent [LCP ConfReq id=0x3c <asyncmap 0x0> <magic 0xf68ca3b4> <pcomp> <accomp>]
Nov 24 12:19:28 arm pppd[5447]: sent [LCP ConfReq id=0x3c <asyncmap 0x0> <magic 0xf68ca3b4> <pcomp> <accomp>]
Nov 24 12:19:32 arm pppd[5447]: sent [LCP ConfReq id=0x3c <asyncmap 0x0> <magic 0xf68ca3b4> <pcomp> <accomp>]
Nov 24 12:19:36 arm pppd[5447]: sent [LCP ConfReq id=0x3c <asyncmap 0x0> <magic 0xf68ca3b4> <pcomp> <accomp>]
Nov 24 12:19:39 arm pppd[5447]: sent [LCP ConfReq id=0x3c <asyncmap 0x0> <magic 0xf68ca3b4> <pcomp> <accomp>]
Nov 24 12:19:40 arm pppd[5447]: rcvd [LCP ConfReq id=0xab <mru 9178> <auth chap MD5> <magic 0x7efec34d>]
Nov 24 12:19:40 arm pppd[5447]: sent [LCP ConfNak id=0xab <auth pap>]
Nov 24 12:19:40 arm pppd[5447]: rcvd [LCP ConfAck id=0x3c <asyncmap 0x0> <magic 0xf68ca3b4> <pcomp> <accomp>]
Nov 24 12:19:40 arm pppd[5447]: rcvd [LCP ConfReq id=0xac <mru 9178> <auth chap MD5> <magic 0x7efec34d>]
Nov 24 12:19:40 arm pppd[5447]: sent [LCP ConfNak id=0xac <auth pap>]
Nov 24 12:19:40 arm pppd[5447]: rcvd [LCP ConfAck id=0x3c <asyncmap 0x0> <magic 0xf68ca3b4> <pcomp> <accomp>]
Nov 24 12:19:40 arm pppd[5447]: rcvd [LCP ConfReq id=0xad <mru 9178> <auth chap MD5> <magic 0x7efec34d>]
Nov 24 12:19:40 arm pppd[5447]: sent [LCP ConfNak id=0xad <auth pap>]
Nov 24 12:19:40 arm pppd[5447]: rcvd [LCP ConfAck id=0x3c <asyncmap 0x0> <magic 0xf68ca3b4> <pcomp> <accomp>]
Nov 24 12:19:40 arm pppd[5447]: rcvd [LCP ConfReq id=0xae <mru 9178> <auth chap MD5> <magic 0x7efec34d>]
Nov 24 12:19:40 arm pppd[5447]: sent [LCP ConfNak id=0xae <auth pap>]
Nov 24 12:19:40 arm pppd[5447]: rcvd [LCP ConfAck id=0x3c <asyncmap 0x0> <magic 0xf68ca3b4> <pcomp> <accomp>]
Nov 24 12:19:40 arm pppd[5447]: rcvd [LCP ConfReq id=0xaf <mru 9178> <auth chap MD5> <magic 0x7efec34d>]
Nov 24 12:19:40 arm pppd[5447]: sent [LCP ConfNak id=0xaf <auth pap>]
Nov 24 12:19:40 arm pppd[5447]: rcvd [LCP ConfReq id=0xb0 <mru 9178> <auth chap MD5> <magic 0x7efec34d>]
Nov 24 12:19:40 arm pppd[5447]: sent [LCP ConfRej id=0xb0 <auth chap MD5>]
Nov 24 12:19:40 arm pppd[5447]: rcvd [LCP ConfAck id=0x3c <asyncmap 0x0> <magic 0xf68ca3b4> <pcomp> <accomp>]
Nov 24 12:19:41 arm pppd[5447]: rcvd [LCP ConfReq id=0xb1 <mru 9178> <auth chap MD5> <magic 0x7efec34d>]
Nov 24 12:19:41 arm pppd[5447]: sent [LCP ConfRej id=0xb1 <auth chap MD5>]
Nov 24 12:19:41 arm pppd[5447]: rcvd [LCP ConfAck id=0x3c <asyncmap 0x0> <magic 0xf68ca3b4> <pcomp> <accomp>]
Nov 24 12:19:41 arm pppd[5447]: rcvd [LCP ConfReq id=0xb2 <mru 9178> <auth chap MD5> <magic 0x7efec34d>]
Nov 24 12:19:41 arm pppd[5447]: sent [LCP ConfRej id=0xb2 <auth chap MD5>]
Nov 24 12:19:41 arm pppd[5447]: rcvd [LCP ConfAck id=0x3c <asyncmap 0x0> <magic 0xf68ca3b4> <pcomp> <accomp>]
Nov 24 12:19:41 arm pppd[5447]: rcvd [LCP ConfReq id=0xb3 <mru 9178> <auth chap MD5> <magic 0x7efec34d>]
Nov 24 12:19:41 arm pppd[5447]: sent [LCP ConfRej id=0xb3 <auth chap MD5>]
Nov 24 12:19:41 arm pppd[5447]: rcvd [LCP ConfAck id=0x3c <asyncmap 0x0> <magic 0xf68ca3b4> <pcomp> <accomp>]
Nov 24 12:19:41 arm pppd[5447]: rcvd [LCP ConfReq id=0xb4 <mru 9178> <auth chap MD5> <magic 0x7efec34d>]
Nov 24 12:19:41 arm pppd[5447]: sent [LCP ConfRej id=0xb4 <auth chap MD5>]
Nov 24 12:19:41 arm pppd[5447]: rcvd [LCP ConfReq id=0xb5 <mru 9178> <magic 0x7efec34d>]
Nov 24 12:19:41 arm pppd[5447]: sent [LCP ConfAck id=0xb5 <mru 9178> <magic 0x7efec34d>]
Nov 24 12:19:41 arm pppd[5447]: sent [LCP EchoReq id=0x0 magic=0xf68ca3b4]
Nov 24 12:19:41 arm pppd[5447]: sent [CCP ConfReq id=0x3c <deflate 15> <deflate(old#) 15> <bsd v1 15>]
Nov 24 12:19:41 arm pppd[5447]: sent [IPCP ConfReq id=0x3e <compress VJ 0f 01> <addr 83.27.15.78> <ms-dns1 0.0.0.0> <ms-dns3 0.0.0.0>]
Nov 24 12:19:41 arm pppd[5447]: rcvd [LCP TermReq id=0xb6]
Nov 24 12:19:41 arm pppd[5447]: LCP terminated by peer
Nov 24 12:19:41 arm pppd[5447]: sent [LCP TermAck id=0xb6]
Nov 24 12:19:44 arm pppd[5447]: Connection terminated.
Nov 24 12:19:44 arm pppd[5447]: tcflush failed: Bad file descriptor
Nov 24 12:19:44 arm pppd[5447]: using channel 197
Nov 24 12:19:44 arm pppd[5447]: Using interface ppp0
Nov 24 12:19:45 arm pppd[5447]: Connect: ppp0 <--> /dev/pts/66
Nov 24 12:19:46 arm pppd[5447]: sent [LCP ConfReq id=0x3d <asyncmap 0x0> <magic 0x688721d3> <pcomp> <accomp>]
Nov 24 12:19:49 arm pppd[5447]: sent [LCP ConfReq id=0x3d <asyncmap 0x0> <magic 0x688721d3> <pcomp> <accomp>]
> > With 2.4.2 there was no problem with ,,tcflush failed: Bad file
> > descriptor'' on the same kernel.
>
> I've seen it before, but I don't think it's actually harmful.
Well, after such disconnect new pppd runs pppoa -I eth1 multiple times
without killing old one and this causes huge load (it's hard to do anything
on the system then). Old, not killed pppoa processes reports multiple
Nov 25 16:18:15 arm pppoa[6387]: Packet not from driver (mac: 0:60:4c:41:53:74)
Nov 25 16:18:15 arm pppoa[6387]: Packet not from driver (mac: 0:60:4c:41:53:74)
Nov 25 16:18:15 arm pppoa[6328]: Packet not from driver (mac: 0:60:4c:41:53:74)
Nov 25 16:18:15 arm pppoa[6328]: Packet not from driver (mac: 0:60:4c:41:53:74)
Shouldn't pppd kill old pty "command" before running new one?
--
Arkadiusz Mi¶kiewicz PLD/Linux Team
http://www.t17.ds.pwr.wroc.pl/~misiek/ http://ftp.pld-linux.org/
^ permalink raw reply [flat|nested] 7+ messages in thread* Re: some change in ppp 2.4.3: tcflush failed: Bad file descriptor
2004-11-23 10:57 some change in ppp 2.4.3: tcflush failed: Bad file descriptor Arkadiusz Miskiewicz
2004-11-23 16:06 ` James Carlson
2004-11-25 15:44 ` Arkadiusz Miskiewicz
@ 2004-11-25 16:09 ` Arkadiusz Miskiewicz
2004-11-25 21:27 ` Paul Mackerras
` (2 subsequent siblings)
5 siblings, 0 replies; 7+ messages in thread
From: Arkadiusz Miskiewicz @ 2004-11-25 16:09 UTC (permalink / raw)
To: linux-ppp
On Thursday 25 of November 2004 16:44, Arkadiusz Miskiewicz wrote:
> Well, after such disconnect new pppd runs pppoa -I eth1 multiple times
> without killing old one and this causes huge load (it's hard to do anything
> on the system then). Old, not killed pppoa processes reports multiple
> Nov 25 16:18:15 arm pppoa[6387]: Packet not from driver (mac:
> 0:60:4c:41:53:74) Nov 25 16:18:15 arm pppoa[6387]: Packet not from driver
> (mac: 0:60:4c:41:53:74) Nov 25 16:18:15 arm pppoa[6328]: Packet not from
> driver (mac: 0:60:4c:41:53:74) Nov 25 16:18:15 arm pppoa[6328]: Packet not
> from driver (mac: 0:60:4c:41:53:74)
>
> Shouldn't pppd kill old pty "command" before running new one?
It looks like this:
[root@arm misiek]# pstree -lpu | grep ppp
|-pppd(17285)-+-sh(17286)---pppoa(17287)
| |-sh(17479)---pppoa(17484)
| `-sh(17539)---pppoa(17540)
|-sh(8386)---pppoa(8390)
new pppoa is created at each retry
--
Arkadiusz Mi¶kiewicz PLD/Linux Team
http://www.t17.ds.pwr.wroc.pl/~misiek/ http://ftp.pld-linux.org/
^ permalink raw reply [flat|nested] 7+ messages in thread* Re: some change in ppp 2.4.3: tcflush failed: Bad file descriptor
2004-11-23 10:57 some change in ppp 2.4.3: tcflush failed: Bad file descriptor Arkadiusz Miskiewicz
` (2 preceding siblings ...)
2004-11-25 16:09 ` Arkadiusz Miskiewicz
@ 2004-11-25 21:27 ` Paul Mackerras
2004-11-25 22:55 ` Arkadiusz Miskiewicz
2004-11-26 0:51 ` Paul Mackerras
5 siblings, 0 replies; 7+ messages in thread
From: Paul Mackerras @ 2004-11-25 21:27 UTC (permalink / raw)
To: linux-ppp
Arkadiusz Miskiewicz writes:
> Shouldn't pppd kill old pty "command" before running new one?
pppd will close its side of the pty device, leading to the program
running on the other side (the script specified in the pty option)
getting an end-of-file on its standard input. It should clean up and
exit when it gets that.
Alternatively you can use a disconnect script to kill it, if your pty
command is too lame to exit on EOF.
Paul.
^ permalink raw reply [flat|nested] 7+ messages in thread* Re: some change in ppp 2.4.3: tcflush failed: Bad file descriptor
2004-11-23 10:57 some change in ppp 2.4.3: tcflush failed: Bad file descriptor Arkadiusz Miskiewicz
` (3 preceding siblings ...)
2004-11-25 21:27 ` Paul Mackerras
@ 2004-11-25 22:55 ` Arkadiusz Miskiewicz
2004-11-26 0:51 ` Paul Mackerras
5 siblings, 0 replies; 7+ messages in thread
From: Arkadiusz Miskiewicz @ 2004-11-25 22:55 UTC (permalink / raw)
To: linux-ppp
On Thursday 25 of November 2004 22:27, Paul Mackerras wrote:
> Arkadiusz Miskiewicz writes:
> > Shouldn't pppd kill old pty "command" before running new one?
>
> pppd will close its side of the pty device, leading to the program
> running on the other side (the script specified in the pty option)
> getting an end-of-file on its standard input. It should clean up and
> exit when it gets that.
>
> Alternatively you can use a disconnect script to kill it, if your pty
> command is too lame to exit on EOF.
Looking into pppoa code I see that read() of 0 is handled (exit(0) in such
case). Did anything change between 2.4.2 and 2.4.3 in this area? 2.4.2 causes
that pppoa terminates properly while 2.4.3 not.
tcflush failed: Bad file descriptor comes from ioctl on -1 descriptor, doesn't
look correct
4196 ioctl(8, JFFS_PRINT_HASH or PPPIOCGFLAGS, 0xbffff3a0) = 0
4196 ioctl(-1, TCFLSH, 0x2) = -1 EBADF (Bad file descriptor)
4196 time([1101422552]) = 1101422552
4196 stat64("/etc/localtime", <unfinished ...>
4555 <... select resumed> ) = 0 (Timeout)
4196 <... stat64 resumed> {st_mode=S_IFREG|0644, st_size–1, ...}) = 0
4555 select(4, [0 3], NULL, NULL, {0, 250} <unfinished ...>
4196 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size–1, ...}) = 0
4196 stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size–1, ...}) = 0
4196 rt_sigaction(SIGPIPE, {0xb7f0a140, [], 0}, {SIG_IGN}, 8) = 0
4196 send(3, "<28>Nov 25 23:42:32 pppd[4196]: tcflush failed: Bad file
descriptor\0", 68, 0) = 68
isn't tcflush failing a reason for a pppoa to not terminate?
> Paul.
--
Arkadiusz Mi¶kiewicz PLD/Linux Team
http://www.t17.ds.pwr.wroc.pl/~misiek/ http://ftp.pld-linux.org/
^ permalink raw reply [flat|nested] 7+ messages in thread* Re: some change in ppp 2.4.3: tcflush failed: Bad file descriptor
2004-11-23 10:57 some change in ppp 2.4.3: tcflush failed: Bad file descriptor Arkadiusz Miskiewicz
` (4 preceding siblings ...)
2004-11-25 22:55 ` Arkadiusz Miskiewicz
@ 2004-11-26 0:51 ` Paul Mackerras
5 siblings, 0 replies; 7+ messages in thread
From: Paul Mackerras @ 2004-11-26 0:51 UTC (permalink / raw)
To: linux-ppp
Arkadiusz Miskiewicz writes:
> Looking into pppoa code I see that read() of 0 is handled (exit(0) in such
> case). Did anything change between 2.4.2 and 2.4.3 in this area? 2.4.2 causes
> that pppoa terminates properly while 2.4.3 not.
Interesting. 2.4.3 has some changes to make sure that we don't leak
file descriptors or leave them open when we shouldn't, but maybe
there's still a bug. Can you send me the whole strace log?
> isn't tcflush failing a reason for a pppoa to not terminate?
Nope.
Paul.
^ permalink raw reply [flat|nested] 7+ messages in thread