No subject

Sun Jul 8 18:14:56 CDT 2012

VPN is restarted.

Has anyone seen this problem before, or any hint for me how to solve
it? I append a log-file of the session to the end of the message.
BTW it doesn't matter which encryption I choose this happens just the same
with any form of MPPE encryption, no matter of MPPE 40-bit or 128-bit or
stateless or non-stateless ...

bye
   Martin

PGP-RSA key available from:
http://horowitz.surfnet.nl:11371/pks/lookup?op=index&search=mm@lunetix.de
-------------------------------------------------------------------------
Mar 13 15:52:43 mel pptpd[1865]: MGR: Launching /usr/sbin/pptpctrl to handle client
Mar 13 15:52:43 mel pptpd[1865]: CTRL: local address = 192.168.100.254
Mar 13 15:52:43 mel pptpd[1865]: CTRL: remote address = 192.168.100.243
Mar 13 15:52:43 mel pptpd[1865]: CTRL: pppd speed = 115200
Mar 13 15:52:43 mel pptpd[1865]: CTRL: pppd options file = /etc/ppp/pptp.options
Mar 13 15:52:43 mel pptpd[1865]: CTRL: Client xxx.xxx.xxx.xxx control connection started
Mar 13 15:52:43 mel pptpd[1865]: CTRL: Received PPTP Control Message (type: 1)
Mar 13 15:52:43 mel pptpd[1865]: CTRL: Made a START CTRL CONN RPLY packet
Mar 13 15:52:43 mel pptpd[1865]: CTRL: I wrote 156 bytes to the client.
Mar 13 15:52:43 mel pptpd[1865]: CTRL: Sent packet to client
Mar 13 15:52:46 mel pptpd[1865]: CTRL: Received PPTP Control Message (type: 7)
Mar 13 15:52:46 mel pptpd[1865]: CTRL: Set parameters to 0 maxbps, 16 window size
Mar 13 15:52:46 mel pptpd[1865]: CTRL: Made a OUT CALL RPLY packet
Mar 13 15:52:46 mel pptpd[1865]: CTRL: Starting call (launching pppd, opening GRE)
Mar 13 15:52:46 mel pptpd[1865]: CTRL: pty_fd = 5
Mar 13 15:52:46 mel pptpd[1865]: CTRL: tty_fd = 6
Mar 13 15:52:46 mel pptpd[1865]: CTRL: I wrote 32 bytes to the client.
Mar 13 15:52:46 mel pptpd[1865]: CTRL: Sent packet to client
Mar 13 15:52:46 mel pptpd[1866]: CTRL (PPPD Launcher): Connection speed = 115200
Mar 13 15:52:46 mel pptpd[1866]: CTRL (PPPD Launcher): local address = 192.168.100.254
Mar 13 15:52:46 mel pptpd[1866]: CTRL (PPPD Launcher): remote address = 192.168.100.243
Mar 13 15:52:46 mel pppd[1866]: pppd 2.3.10 started by root, uid 0
Mar 13 15:52:46 mel pppd[1866]: Using interface ppp0
Mar 13 15:52:46 mel pppd[1866]: Connect: ppp0 <--> /dev/pts/0
Mar 13 15:52:46 mel pppd[1866]: sent [LCP ConfReq id=0x1 <mru 808> <asyncmap 0x0> <auth chap 81> <magic 0x873988c9> <pcomp> <accomp>]
Mar 13 15:52:46 mel pppd[1866]: Timeout 0x8050164:0x8077660 in 3 seconds.
Mar 13 15:52:47 mel pppd[1866]: rcvd [LCP ConfReq id=0x1 <magic 0xf4995e8> <pcomp> <accomp>]
Mar 13 15:52:47 mel pppd[1866]: lcp_reqci: returning CONFACK.
Mar 13 15:52:47 mel pppd[1866]: sent [LCP ConfAck id=0x1 <magic 0xf4995e8> <pcomp> <accomp>]
Mar 13 15:52:47 mel pppd[1866]: rcvd [LCP ConfAck id=0x1 <mru 808> <asyncmap 0x0> <auth chap 81> <magic 0x873988c9> <pcomp> <accomp>]
Mar 13 15:52:47 mel pppd[1866]: Untimeout 0x8050164:0x8077660.
Mar 13 15:52:47 mel pppd[1866]: sent [CHAP Challenge id=0x1 <af3e4d1a54b569a5813cbe56271ffb57>, name = "fmnet"]
Mar 13 15:52:47 mel pppd[1866]: Timeout 0x80558c0:0x8077940 in 3 seconds.
Mar 13 15:52:48 mel pppd[1866]: rcvd [CHAP Response id=0x1 <4e0fcd46d0f0144cda90583534d0bd600000000000000000e840fe64ab9e1296b1c7500c62b3633Mar 13 15:52:48 mel pppd[1866]: Untimeout 0x80558c0:0x8077940.
Mar 13 15:52:48 mel pppd[1866]: ChapReceiveResponse: rcvd type MS-CHAP-V2
Mar 13 15:52:48 mel pppd[1866]: sent [CHAP Success id=0x1 "S=1DF79A1F1D0632DEBA43D7E05CD3492A90550AAE"]
Mar 13 15:52:48 mel pppd[1866]: sent [IPCP ConfReq id=0x1 <addr 192.168.100.254>]
Mar 13 15:52:48 mel pppd[1866]: Timeout 0x8050164:0x80778c0 in 3 seconds.
Mar 13 15:52:48 mel pppd[1866]: sent [CCP ConfReq id=0x1 <mppe 1 0 0 60>]
Mar 13 15:52:48 mel pppd[1866]: Timeout 0x8050164:0x8077a00 in 3 seconds.
Mar 13 15:52:48 mel pppd[1866]: MSCHAP-v2 peer authentication succeeded for mnmuelle
Mar 13 15:52:48 mel kernel: mppe_comp_alloc(): compress rejected: opt_len=19,o[0]=12,o[1]=6 
Mar 13 15:52:48 mel last message repeated 2 times
Mar 13 15:52:49 mel pppd[1866]: rcvd [CCP ConfReq id=0x1 <mppe 1 0 0 70>]
Mar 13 15:52:49 mel kernel: mppe_comp_alloc(): compress rejected: opt_len=19,o[0]=12,o[1]=6 
Mar 13 15:52:49 mel pppd[1866]: sent [CCP ConfNak id=0x1 <mppe 1 0 0 60>]
Mar 13 15:52:49 mel pptpd[1865]: GRE: Discarding out of order packet
Mar 13 15:52:49 mel pppd[1866]: rcvd [CCP ConfNak id=0x1 <mppe 1 0 0 40>]
Mar 13 15:52:49 mel pppd[1866]: Untimeout 0x8050164:0x8077a00.
Mar 13 15:52:49 mel pppd[1866]: sent [CCP ConfReq id=0x2 <mppe 1 0 0 40>]
Mar 13 15:52:49 mel pppd[1866]: Timeout 0x8050164:0x8077a00 in 3 seconds.
Mar 13 15:52:49 mel kernel: mppe_comp_alloc(): compress rejected: opt_len=35,o[0]=12,o[1]=6 
Mar 13 15:52:49 mel pppd[1866]: rcvd [CCP ConfAck id=0x2 <mppe 1 0 0 40>]
Mar 13 15:52:51 mel pppd[1866]: sent [IPCP ConfReq id=0x1 <addr 192.168.100.254>]
Mar 13 15:52:51 mel pppd[1866]: Timeout 0x8050164:0x80778c0 in 3 seconds.
Mar 13 15:52:52 mel pppd[1866]: rcvd [IPCP ConfAck id=0x1 <addr 192.168.100.254>]
Mar 13 15:52:52 mel pppd[1866]: rcvd [CCP ConfReq id=0x2 <mppe 1 0 0 70>]
Mar 13 15:52:52 mel pppd[1866]: sent [CCP ConfNak id=0x2 <mppe 1 0 0 60>]
Mar 13 15:52:52 mel kernel: mppe_comp_alloc(): compress rejected: opt_len=19,o[0]=12,o[1]=6 
Mar 13 15:52:52 mel pppd[1866]: rcvd [IPCP ConfReq id=0x2 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-wins 0.0.0.0> <ms-dns3 0.0.0.0> <ms-wins 0.0Mar 13 15:52:52 mel pppd[1866]: ipcp: returning Configure-NAK
Mar 13 15:52:52 mel pppd[1866]: sent [IPCP ConfNak id=0x2 <addr 192.168.100.243> <ms-dns1 192.168.100.9> <ms-wins 192.168.100.9> <ms-dns3 1Mar 13 15:52:52 mel pppd[1866]: sent [CCP ConfReq id=0x2 <mppe 1 0 0 40>]
Mar 13 15:52:52 mel pppd[1866]: Timeout 0x8050164:0x8077a00 in 3 seconds.
Mar 13 15:52:52 mel kernel: mppe_comp_alloc(): compress rejected: opt_len=35,o[0]=12,o[1]=6 
Mar 13 15:52:52 mel pppd[1866]: rcvd [CCP ConfReq id=0x3 <mppe 1 0 0 40>]
Mar 13 15:52:52 mel pppd[1866]: sent [CCP ConfAck id=0x3 <mppe 1 0 0 40>]
Mar 13 15:52:52 mel kernel: mppe_comp_alloc(): compress rejected: opt_len=35,o[0]=12,o[1]=6 
Mar 13 15:52:52 mel kernel: mppe_comp_init(): compress rejected: opt_len=6,o[0]=12,o[1]=6 
Mar 13 15:52:52 mel pppd[1866]: rcvd [IPCP ConfReq id=0x3 <addr 192.168.100.243> <ms-dns1 192.168.100.9> <ms-wins 192.168.100.9> <ms-dns3 1Mar 13 15:52:52 mel pppd[1866]: ipcp: returning Configure-ACK
Mar 13 15:52:52 mel pppd[1866]: sent [IPCP ConfAck id=0x3 <addr 192.168.100.243> <ms-dns1 192.168.100.9> <ms-wins 192.168.100.9> <ms-dns3 1Mar 13 15:52:52 mel pppd[1866]: Untimeout 0x8050164:0x80778c0.
Mar 13 15:52:52 mel pppd[1866]: ipcp: up
Mar 13 15:52:52 mel pppd[1866]: found interface eth0 for proxy arp
Mar 13 15:52:52 mel pppd[1866]: local  IP address 192.168.100.254
Mar 13 15:52:52 mel pppd[1866]: remote IP address 192.168.100.243
Mar 13 15:52:52 mel pppd[1866]: Script /etc/ppp/ip-up started (pid 1868)
Mar 13 15:52:52 mel pppd[1866]: rcvd [CCP ConfAck id=0x2 <mppe 1 0 0 40>]
Mar 13 15:52:52 mel pppd[1866]: Untimeout 0x8050164:0x8077a00.
Mar 13 15:52:52 mel pppd[1866]: MPPE 128 bit, stateless compression enabled
Mar 13 15:52:52 mel pppd[1866]: Script /etc/ppp/ip-up finished (pid 1868), status = 0x0
Mar 13 15:52:57 mel pppd[1866]: rcvd [CCP ResetReq id=0x4]
Mar 13 15:52:57 mel pppd[1866]: sent [CCP ResetAck id=0x4]
Mar 13 15:52:57 mel kernel: mppe_comp_reset 
Mar 13 15:53:15 mel PAM_unix[917]: (login) session opened for user root by LOGIN(uid=0)
Mar 13 15:53:15 mel login: ROOT LOGIN ON tty3
Mar 13 15:53:32 mel pppd[1866]: rcvd [CCP ResetReq id=0x5]
Mar 13 15:53:32 mel pppd[1866]: sent [CCP ResetAck id=0x5]
Mar 13 15:53:32 mel kernel: mppe_comp_reset 
Mar 13 15:53:43 mel pppd[1866]: rcvd [CCP ResetReq id=0x6]
Mar 13 15:53:43 mel pppd[1866]: sent [CCP ResetAck id=0x6]
Mar 13 15:53:43 mel kernel: mppe_comp_reset 
Mar 13 15:53:46 mel pptpd[1865]: CTRL: Received PPTP Control Message (type: 5)
Mar 13 15:53:46 mel pptpd[1865]: CTRL: Made a ECHO RPLY packet
Mar 13 15:53:46 mel pptpd[1865]: CTRL: I wrote 20 bytes to the client.
Mar 13 15:53:46 mel pptpd[1865]: CTRL: Sent packet to client
Mar 13 15:53:51 mel pppd[1866]: rcvd [CCP ResetReq id=0x7]
Mar 13 15:53:51 mel pppd[1866]: sent [CCP ResetAck id=0x7]
Mar 13 15:53:51 mel kernel: mppe_comp_reset 
Mar 13 15:54:02 mel pppd[1866]: rcvd [CCP ResetReq id=0x8]
Mar 13 15:54:02 mel pppd[1866]: sent [CCP ResetAck id=0x8]
Mar 13 15:54:02 mel kernel: mppe_comp_reset 
Mar 13 15:54:04 mel pppd[1866]: rcvd [CCP ResetReq id=0x9]
Mar 13 15:54:04 mel pppd[1866]: sent [CCP ResetAck id=0x9]
Mar 13 15:54:04 mel kernel: mppe_comp_reset 
Mar 13 15:54:12 mel pppd[1866]: rcvd [CCP ResetReq id=0xa]
Mar 13 15:54:12 mel pppd[1866]: sent [CCP ResetAck id=0xa]
Mar 13 15:54:12 mel kernel: mppe_comp_reset 
Mar 13 15:54:19 mel pppd[1866]: rcvd [CCP ResetReq id=0xb]
Mar 13 15:54:19 mel pppd[1866]: sent [CCP ResetAck id=0xb]
Mar 13 15:54:19 mel kernel: mppe_comp_reset 
Mar 13 15:54:19 mel pppd[1866]: rcvd [CCP ResetReq id=0xd]
Mar 13 15:54:19 mel pppd[1866]: sent [CCP ResetAck id=0xd]
Mar 13 15:54:19 mel kernel: mppe_comp_reset 
Mar 13 15:54:19 mel pptpd[1865]: GRE: Discarding out of order packet
Mar 13 15:54:22 mel pppd[1866]: rcvd [CCP ResetReq id=0xe]
Mar 13 15:54:22 mel pppd[1866]: sent [CCP ResetAck id=0xe]
Mar 13 15:54:22 mel kernel: mppe_comp_reset 
Mar 13 15:54:23 mel pppd[1866]: rcvd [CCP ResetReq id=0xf]
Mar 13 15:54:23 mel pppd[1866]: sent [CCP ResetAck id=0xf]
Mar 13 15:54:23 mel kernel: mppe_comp_reset 
Mar 13 15:54:26 mel pppd[1866]: rcvd [CCP ResetReq id=0x10]
Mar 13 15:54:26 mel pppd[1866]: sent [CCP ResetAck id=0x10]
Mar 13 15:54:26 mel kernel: mppe_comp_reset 
Mar 13 15:54:28 mel pppd[1866]: rcvd [CCP ResetReq id=0x12]
Mar 13 15:54:28 mel pppd[1866]: sent [CCP ResetAck id=0x12]
Mar 13 15:54:28 mel kernel: mppe_comp_reset 
Mar 13 15:54:28 mel pptpd[1865]: GRE: Discarding out of order packet
Mar 13 15:54:28 mel pppd[1866]: rcvd [CCP ResetReq id=0x13]
Mar 13 15:54:28 mel pppd[1866]: sent [CCP ResetAck id=0x13]
Mar 13 15:54:28 mel kernel: mppe_comp_reset 
Mar 13 15:54:38 mel pppd[1866]: rcvd [CCP ResetReq id=0x14]
Mar 13 15:54:38 mel pppd[1866]: sent [CCP ResetAck id=0x14]
Mar 13 15:54:38 mel kernel: mppe_comp_reset 
Mar 13 15:54:41 mel pppd[1866]: rcvd [CCP ResetReq id=0x15]
Mar 13 15:54:41 mel pppd[1866]: sent [CCP ResetAck id=0x15]
Mar 13 15:54:41 mel kernel: mppe_comp_reset 
Mar 13 15:54:41 mel pppd[1866]: rcvd [Compressed data] 90 50 71 8d ee d6 37 c8 ...
Mar 13 15:54:42 mel pppd[1866]: rcvd [Compressed data] 90 51 2f 23 f2 04 06 df ...
Mar 13 15:54:43 mel pppd[1866]: rcvd [Compressed data] 90 52 85 76 6b 80 b3 33 ...
Mar 13 15:54:45 mel pppd[1866]: rcvd [CCP ResetReq id=0x16]
Mar 13 15:54:45 mel pppd[1866]: sent [CCP ResetAck id=0x16]
Mar 13 15:54:45 mel kernel: mppe_comp_reset 
Mar 13 15:54:45 mel pppd[1866]: rcvd [Compressed data] 90 53 06 9f 17 f9 69 c1 ...
Mar 13 15:54:46 mel pppd[1866]: rcvd [Compressed data] 90 54 db 09 00 ec 54 4e ...
Mar 13 15:54:47 mel pptpd[1865]: CTRL: Received PPTP Control Message (type: 5)
Mar 13 15:54:47 mel pptpd[1865]: CTRL: Made a ECHO RPLY packet
Mar 13 15:54:47 mel pptpd[1865]: CTRL: I wrote 20 bytes to the client.
Mar 13 15:54:47 mel pptpd[1865]: CTRL: Sent packet to client
Mar 13 15:54:48 mel pppd[1866]: rcvd [CCP ResetReq id=0x17]
Mar 13 15:54:48 mel pppd[1866]: sent [CCP ResetAck id=0x17]
Mar 13 15:54:48 mel kernel: mppe_comp_reset 
Mar 13 15:54:49 mel pppd[1866]: rcvd [Compressed data] 90 55 58 59 13 e4 a1 10 ...
Mar 13 15:54:49 mel pppd[1866]: rcvd [Compressed data] 90 56 4b c6 15 e5 6d e1 ...
Mar 13 15:54:50 mel pppd[1866]: rcvd [Compressed data] 90 57 c6 1f 98 c1 11 2a ...
Mar 13 15:54:51 mel pppd[1866]: rcvd [Compressed data] 90 58 73 f4 5d e4 88 ca ...
Mar 13 15:54:52 mel pppd[1866]: rcvd [Compressed data] 90 59 0a f5 5f ba a5 41 ...
Mar 13 15:54:53 mel pppd[1866]: rcvd [Compressed data] 90 5a d5 23 15 6f 2d 82 ...
Mar 13 15:54:55 mel pppd[1866]: rcvd [LCP TermReq id=0x2]
Mar 13 15:54:55 mel pppd[1866]: LCP terminated by peer
Mar 13 15:54:55 mel pppd[1866]: ipcp: down
Mar 13 15:54:55 mel pppd[1866]: Untimeout 0x805957c:0x0.
Mar 13 15:54:55 mel pppd[1866]: Script /etc/ppp/ip-down started (pid 1913)
Mar 13 15:54:55 mel pppd[1866]: Timeout 0x8050164:0x8077660 in 3 seconds.
Mar 13 15:54:55 mel pppd[1866]: sent [LCP TermAck id=0x2]
Mar 13 15:54:55 mel pppd[1866]: Script /etc/ppp/ip-down finished (pid 1913), status = 0x0
Mar 13 15:54:56 mel pptpd[1865]: CTRL: Received PPTP Control Message (type: 12)
Mar 13 15:54:56 mel pptpd[1865]: CTRL: Made a CALL DISCONNECT RPLY packet
Mar 13 15:54:56 mel pptpd[1865]: CTRL: Received CALL CLR request (closing call)
Mar 13 15:54:56 mel pptpd[1865]: CTRL: I wrote 148 bytes to the client.
Mar 13 15:54:56 mel pptpd[1865]: CTRL: Sent packet to client
Mar 13 15:54:56 mel pptpd[1865]: CTRL: Error with select(), quitting
Mar 13 15:54:56 mel pptpd[1865]: CTRL: Client xxx.xxx.xxx.xxx control connection finished
Mar 13 15:54:56 mel pptpd[1865]: CTRL: Exiting now
Mar 13 15:54:56 mel pptpd[921]: MGR: Reaped child 1865
Mar 13 15:54:56 mel pppd[1866]: Modem hangup
Mar 13 15:54:56 mel pppd[1866]: Untimeout 0x8050164:0x8077660.
Mar 13 15:54:56 mel pppd[1866]: Connection terminated.
Mar 13 15:54:56 mel pppd[1866]: Connect time 2.2 minutes.
Mar 13 15:54:56 mel pppd[1866]: Sent 16521 bytes, received 10188 bytes.
Mar 13 15:54:56 mel pppd[1866]: Exit.
-------------------------------------------------------------------------