GRE: read(fd=6, buffer=8058640, len=8196) from PTY failed

[Brian Lavender-3]

My pptpd server was working. Then I upgraded to Debian Lenny and now
it's broke. :( The error I see thus far is below. It looks like for GRE,
a read failed. Any ideas what broke?

Thanks,

brian

Specific error:
GRE: read(fd=6,buffer=8058640,len=8196) from PTY failed: status = -1 error = Input/output error, usually caused by unexpected termination of pppd, check option syntax and pppd logs

Detail connection output:
Jun 14 18:08:27 mammoth pptpd[28107]: MGR: Launching /usr/sbin/pptpctrl to handle client
Jun 14 18:08:27 mammoth pptpd[28107]: CTRL: local address = 192.168.1.111
Jun 14 18:08:27 mammoth pptpd[28107]: CTRL: remote address = 192.168.3.112
Jun 14 18:08:27 mammoth pptpd[28107]: CTRL: pppd options file = /etc/ppp/pptpd-options
Jun 14 18:08:27 mammoth pptpd[28107]: CTRL: Client 76.191.246.9 control connection started
Jun 14 18:08:27 mammoth pptpd[28107]: CTRL: Received PPTP Control Message (type: 1)
Jun 14 18:08:27 mammoth pptpd[28107]: CTRL: Made a START CTRL CONN RPLY packet
Jun 14 18:08:27 mammoth pptpd[28107]: CTRL: I wrote 156 bytes to the client.
Jun 14 18:08:27 mammoth pptpd[28107]: CTRL: Sent packet to client
Jun 14 18:08:28 mammoth pptpd[28107]: CTRL: Received PPTP Control Message (type: 7)
Jun 14 18:08:28 mammoth pptpd[28107]: CTRL: Set parameters to 10000000 maxbps, 3 window size
Jun 14 18:08:28 mammoth pptpd[28107]: CTRL: Made a OUT CALL RPLY packet
Jun 14 18:08:28 mammoth pptpd[28107]: CTRL: Starting call (launching pppd, opening GRE)
Jun 14 18:08:28 mammoth pptpd[28107]: CTRL: pty_fd = 6
Jun 14 18:08:28 mammoth pptpd[28107]: CTRL: tty_fd = 7
Jun 14 18:08:28 mammoth pptpd[28108]: CTRL (PPPD Launcher): program binary = /usr/sbin/pppd
Jun 14 18:08:28 mammoth pptpd[28108]: CTRL (PPPD Launcher): local address = 192.168.1.111
Jun 14 18:08:28 mammoth pptpd[28108]: CTRL (PPPD Launcher): remote address = 192.168.3.112
Jun 14 18:08:28 mammoth pppd[28108]: Plugin /usr/lib/pptpd/pptpd-logwtmp.so loaded.
Jun 14 18:08:28 mammoth pppd[28108]: pptpd-logwtmp: $Version$
Jun 14 18:08:28 mammoth pppd[28108]: pppd options in effect:
Jun 14 18:08:28 mammoth pppd[28108]: debug^I^I# (from /etc/ppp/pptpd-options)
Jun 14 18:08:28 mammoth pppd[28108]: domain marquis-sys.com^I^I# (from /etc/ppp/pptpd-options)
Jun 14 18:08:28 mammoth pppd[28108]: dump^I^I# (from /etc/ppp/pptpd-options)
Jun 14 18:08:28 mammoth pppd[28108]: plugin /usr/lib/pptpd/pptpd-logwtmp.so^I^I# (from command line)
Jun 14 18:08:28 mammoth pppd[28108]: +mschap-v2^I^I# (from /etc/ppp/pptpd-options)
Jun 14 18:08:28 mammoth pppd[28108]: name debian^I^I# (from /etc/ppp/pptpd-options)
Jun 14 18:08:28 mammoth pppd[28108]: pptpd-original-ip 76.191.246.9^I^I# (from command line)
Jun 14 18:08:28 mammoth pppd[28108]: 115200^I^I# (from command line)
Jun 14 18:08:28 mammoth pppd[28108]: lock^I^I# (from /etc/ppp/pptpd-options)
Jun 14 18:08:28 mammoth pppd[28108]: crtscts^I^I# (from /etc/ppp/options)
Jun 14 18:08:28 mammoth pppd[28108]: local^I^I# (from command line)
Jun 14 18:08:28 mammoth pppd[28108]: asyncmap 0^I^I# (from /etc/ppp/options)
Jun 14 18:08:28 mammoth pppd[28108]: mru 1450^I^I# (from /etc/ppp/pptpd-options)
Jun 14 18:08:28 mammoth pppd[28108]: mtu 1450^I^I# (from /etc/ppp/pptpd-options)
Jun 14 18:08:28 mammoth pppd[28108]: lcp-echo-failure 4^I^I# (from /etc/ppp/options)
Jun 14 18:08:28 mammoth pppd[28108]: lcp-echo-interval 30^I^I# (from /etc/ppp/options)
Jun 14 18:08:28 mammoth pppd[28108]: hide-password^I^I# (from /etc/ppp/options)
Jun 14 18:08:28 mammoth pppd[28108]: ipparam 76.191.246.9^I^I# (from command line)
Jun 14 18:08:28 mammoth pppd[28108]: ms-dns xxx # [don't know how to print value]^I^I# (from /etc/ppp/pptpd-options)
Jun 14 18:08:28 mammoth pppd[28108]: ms-wins xxx # [don't know how to print value]^I^I# (from /etc/ppp/pptpd-options)
Jun 14 18:08:28 mammoth pppd[28108]: nodefaultroute^I^I# (from /etc/ppp/pptpd-options)
Jun 14 18:08:28 mammoth pppd[28108]: proxyarp^I^I# (from /etc/ppp/pptpd-options)
Jun 14 18:08:28 mammoth pppd[28108]: netmask 255.255.255.0^I^I# (from /etc/ppp/pptpd-options)
Jun 14 18:08:28 mammoth pppd[28108]: 192.168.1.111:192.168.3.112^I^I# (from command line)
Jun 14 18:08:28 mammoth pppd[28108]: ^I^I# (from /etc/ppp/pptpd-options)
Jun 14 18:08:28 mammoth pppd[28108]: +mppe-128^I^I# (from /etc/ppp/pptpd-options)
Jun 14 18:08:28 mammoth pppd[28108]: nomppe-stateful^I^I# (from /etc/ppp/pptpd-options)
Jun 14 18:08:28 mammoth pppd[28108]: noipx^I^I# (from /etc/ppp/options)
Jun 14 18:08:28 mammoth pppd[28108]: pppd 2.4.4 started by root, uid 0
Jun 14 18:08:28 mammoth pptpd[28107]: CTRL: I wrote 32 bytes to the client.
Jun 14 18:08:28 mammoth pptpd[28107]: CTRL: Sent packet to client
Jun 14 18:08:28 mammoth pppd[28108]: using channel 8
Jun 14 18:08:28 mammoth pppd[28108]: Using interface ppp1
Jun 14 18:08:28 mammoth pppd[28108]: Connect: ppp1 <--> /dev/pts/3
Jun 14 18:08:28 mammoth pppd[28108]: sent [LCP ConfReq id=0x1 <mru 1450> <asyncmap 0x0> <auth chap MS-v2> <magic 0x359fb964> <pcomp> <accomp>]
Jun 14 18:08:28 mammoth pptpd[28107]: GRE: Bad checksum from pppd.
Jun 14 18:08:28 mammoth pptpd[28107]: GRE: accepting packet #1
Jun 14 18:08:28 mammoth pppd[28108]: rcvd [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0xbdd9c5b6> <pcomp> <accomp>]
Jun 14 18:08:28 mammoth pppd[28108]: sent [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0xbdd9c5b6> <pcomp> <accomp>]
Jun 14 18:08:28 mammoth pptpd[28107]: GRE: accepting packet #2
Jun 14 18:08:28 mammoth pppd[28108]: rcvd [LCP ConfAck id=0x1 <mru 1450> <asyncmap 0x0> <auth chap MS-v2> <magic 0x359fb964> <pcomp> <accomp>]
Jun 14 18:08:28 mammoth pppd[28108]: sent [LCP EchoReq id=0x0 magic=0x359fb964]
Jun 14 18:08:28 mammoth pppd[28108]: sent [CHAP Challenge id=0x3e <6e0949a3c2449149335db7204dc309bf>, name = "debian"]
Jun 14 18:08:28 mammoth pptpd[28107]: GRE: accepting packet #3
Jun 14 18:08:28 mammoth pppd[28108]: rcvd [LCP EchoRep id=0x0 magic=0xbdd9c5b6]
Jun 14 18:08:28 mammoth pptpd[28107]: GRE: accepting packet #4
Jun 14 18:08:28 mammoth pppd[28108]: rcvd [CHAP Response id=0x3e <dcd8cf1b5642c5e34f785696f3e930690000000000000000b5895872443a9316dbdfd98afcd597de1fcd428680d1381700>, name = "brian"]
Jun 14 18:08:28 mammoth pppd[28108]: sent [CHAP Success id=0x3e "S=D302F4CEAD692451F4C674E33FB0D1F71E8352D4 M=Access granted"]
Jun 14 18:08:28 mammoth pppd[28108]: sent [CCP ConfReq id=0x1 <mppe +H -M +S +L -D -C>]
Jun 14 18:08:28 mammoth pptpd[28107]: GRE: accepting packet #5
Jun 14 18:08:28 mammoth pppd[28108]: rcvd [CCP ConfReq id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>]
Jun 14 18:08:28 mammoth pppd[28108]: MPPE required but peer negotiation failed
Jun 14 18:08:28 mammoth pppd[28108]: sent [LCP TermReq id=0x2 "MPPE required but peer negotiation failed"]
Jun 14 18:08:28 mammoth pppd[28108]: sent [CCP ConfRej id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>]
Jun 14 18:08:28 mammoth pptpd[28107]: GRE: accepting packet #6
Jun 14 18:08:28 mammoth pppd[28108]: rcvd [IPCP ConfReq id=0x1 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns3 0.0.0.0>]
Jun 14 18:08:28 mammoth pppd[28108]: Discarded non-LCP packet when LCP not open
Jun 14 18:08:28 mammoth pptpd[28107]: GRE: accepting packet #7
Jun 14 18:08:28 mammoth pppd[28108]: rcvd [CCP ConfRej id=0x1 <mppe +H -M +S +L -D -C>]
Jun 14 18:08:28 mammoth pppd[28108]: Discarded non-LCP packet when LCP not open
Jun 14 18:08:28 mammoth pptpd[28107]: GRE: accepting packet #8
Jun 14 18:08:28 mammoth pppd[28108]: rcvd [LCP TermAck id=0x2]
Jun 14 18:08:28 mammoth pppd[28108]: Connection terminated.
Jun 14 18:08:28 mammoth pppd[28108]: Connect time 0.0 minutes.
Jun 14 18:08:28 mammoth pppd[28108]: Sent 10 bytes, received 15 bytes.
Jun 14 18:08:28 mammoth pppd[28108]: Exit.
Jun 14 18:08:28 mammoth pptpd[28107]: GRE: read(fd=6,buffer=8058640,len=8196) from PTY failed: status = -1 error = Input/output error, usually caused by unexpected termination of pppd, check option syntax and pppd logs
Jun 14 18:08:28 mammoth pptpd[28107]: CTRL: PTY read or GRE write failed (pty,gre)=(6,7)
Jun 14 18:08:28 mammoth pptpd[28107]: CTRL: Reaping child PPP[28108]
Jun 14 18:08:28 mammoth pptpd[28107]: CTRL: Client 76.191.246.9 control connection finished
Jun 14 18:08:28 mammoth pptpd[28107]: CTRL: Exiting now
Jun 14 18:08:28 mammoth pptpd[28105]: MGR: Reaped child 28107


--
Brian Lavender
http://www.brie.com/brian/

------------------------------------------------------------------------------
Crystal Reports - New Free Runtime and 30 Day Trial
Check out the new simplified licensing option that enables unlimited
royalty-free distribution of the report engine for externally facing
server and web deployment.
http://p.sf.net/sfu/businessobjects
_______________________________________________
Poptop-server mailing list
Poptop-server@...
https://lists.sourceforge.net/lists/listinfo/poptop-server

[James Cameron-2]

On Sun, Jun 14, 2009 at 06:17:51PM -0700, Brian Lavender wrote:
> Jun 14 18:08:28 mammoth pppd[28108]: sent [CCP ConfReq id=0x1 <mppe +H -M +S +L -D -C>]
> Jun 14 18:08:28 mammoth pppd[28108]: rcvd [CCP ConfReq id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>]
> Jun 14 18:08:28 mammoth pppd[28108]: MPPE required but peer negotiation failed

The above is the event which prevents further progress.  The host
proposes encryption, and it receives a proposal for no encryption from
the peer.

See if the older version of package ppp brings back normal operation.

> Jun 14 18:08:28 mammoth pptpd[28107]: GRE: read(fd=6,buffer=8058640,len=8196) from PTY failed: status = -1 error = Input/output error, usually caused by unexpected termination of pppd, check option syntax and pppd logs
> Jun 14 18:08:28 mammoth pptpd[28107]: CTRL: PTY read or GRE write failed (pty,gre)=(6,7)

The above is merely the cascade response.

--
James Cameron                         http://quozl.netrek.org/
HP Open Source, Volunteer             http://opensource.hp.com/
PPTP Client Project, Release Engineer http://pptpclient.sourceforge.net/

------------------------------------------------------------------------------
Crystal Reports - New Free Runtime and 30 Day Trial
Check out the new simplified licensing option that enables unlimited
royalty-free distribution of the report engine for externally facing
server and web deployment.
http://p.sf.net/sfu/businessobjects
_______________________________________________
Poptop-server mailing list
Poptop-server@...
https://lists.sourceforge.net/lists/listinfo/poptop-server

[Brian Lavender-3]

On Mon, Jun 15, 2009 at 12:47:29PM +1000, James Cameron wrote:

> On Sun, Jun 14, 2009 at 06:17:51PM -0700, Brian Lavender wrote:
> > Jun 14 18:08:28 mammoth pppd[28108]: sent [CCP ConfReq id=0x1 <mppe +H -M +S +L -D -C>]
> > Jun 14 18:08:28 mammoth pppd[28108]: rcvd [CCP ConfReq id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>]
> > Jun 14 18:08:28 mammoth pppd[28108]: MPPE required but peer negotiation failed
>
> The above is the event which prevents further progress.  The host
> proposes encryption, and it receives a proposal for no encryption from
> the peer.
>
> See if the older version of package ppp brings back normal operation.

It was my client on Ubuntu. After checking, I found the option to add
mppe encryption, but.... it was unchecked. Thanks for the help.

brian
--
Brian Lavender
http://www.brie.com/brian/

------------------------------------------------------------------------------
Crystal Reports - New Free Runtime and 30 Day Trial
Check out the new simplified licensing option that enables unlimited
royalty-free distribution of the report engine for externally facing
server and web deployment.
http://p.sf.net/sfu/businessobjects
_______________________________________________
Poptop-server mailing list
Poptop-server@...
https://lists.sourceforge.net/lists/listinfo/poptop-server