Package: l2tpd Version: 0.70-pre20031121 When this happens, it wedges the whole l2tpd system for all users -- existing connections freeze and new ones can't be established. This makes l2tpd unusable because when one user experiences the random fault, all users are affected, and the ipsec/l2tp daemons have to be restarted.
My claim that it's random comes from multiple reconnects/disconnects from the same client. It will work about 2/3 of the time with no problems. On the remaining 1/3, when the client disconnects, the pppd process remains behind, wedging l2tpd etc. I applied the patches here (most have already been applied or don't apply any more), and it apears to have fixed the problem: http://www.jacco2.dds.nl/networking/tarballs/l2tpd-10jdl.tgz Here is a sample log from a failed connect/disconnect cycle: Feb 18 12:15:01 lithium l2tpd[19210]: ourtid = 31427, entropy_buf = 7ac3 Feb 18 12:15:01 lithium l2tpd[19210]: ourcid = 33679, entropy_buf = 838f Feb 18 12:15:01 lithium l2tpd[19210]: check_control: control, cid = 0, Ns = 0, Nr = 0 Feb 18 12:15:01 lithium l2tpd[19210]: handle_avps: handling avp's for tunnel 31427, call 33679 Feb 18 12:15:01 lithium l2tpd[19210]: message_type_avp: message type 1 (Start-Control-Connection-Request) Feb 18 12:15:01 lithium l2tpd[19210]: protocol_version_avp: peer is using version 1, revision 0. Feb 18 12:15:01 lithium l2tpd[19210]: framing_caps_avp: supported peer frames:async sync Feb 18 12:15:01 lithium l2tpd[19210]: hostname_avp: peer reports hostname '' Feb 18 12:15:01 lithium l2tpd[19210]: assigned_tunnel_avp: using peer's tunnel 102 Feb 18 12:15:01 lithium l2tpd[19210]: receive_window_size_avp: peer wants RWS of 4. Will use flow control. Feb 18 12:15:01 lithium l2tpd[19210]: check_control: control, cid = 0, Ns = 1, Nr = 1 Feb 18 12:15:01 lithium l2tpd[19210]: handle_avps: handling avp's for tunnel 31427, call 33679 Feb 18 12:15:01 lithium l2tpd[19210]: message_type_avp: message type 3 (Start-Control-Connection-Connected) Feb 18 12:15:01 lithium l2tpd[19210]: control_finish: Connection established to xx.xx.xx.xx, 50902. Local: 31427, Remote: 102. LNS session is 'default' Feb 18 12:15:01 lithium l2tpd[19210]: check_control: control, cid = 0, Ns = 2, Nr = 1 Feb 18 12:15:01 lithium l2tpd[19210]: handle_avps: handling avp's for tunnel 31427, call 33679 Feb 18 12:15:01 lithium l2tpd[19210]: message_type_avp: message type 10 (Incoming-Call-Request) Feb 18 12:15:01 lithium l2tpd[19210]: message_type_avp: new incoming call Feb 18 12:15:01 lithium l2tpd[19210]: ourcid = 45349, entropy_buf = b125 Feb 18 12:15:01 lithium l2tpd[19210]: assigned_session_avp: assigned session id: 4736 Feb 18 12:15:01 lithium l2tpd[19210]: call_serno_avp: serial number is 1 Feb 18 12:15:01 lithium l2tpd[19210]: check_control: control, cid = 4736, Ns = 3, Nr = 2 Feb 18 12:15:01 lithium l2tpd[19210]: handle_avps: handling avp's for tunnel 31427, call 45349 Feb 18 12:15:01 lithium l2tpd[19210]: message_type_avp: message type 12 (Incoming-Call-Connected) Feb 18 12:15:01 lithium l2tpd[19210]: tx_speed_avp: transmit baud rate is 1000000 Feb 18 12:15:01 lithium l2tpd[19210]: frame_type_avp: peer uses:async frames Feb 18 12:15:01 lithium l2tpd[19210]: start_pppd: I'm running: Feb 18 12:15:01 lithium l2tpd[19210]: "/usr/sbin/pppd" Feb 18 12:15:01 lithium l2tpd[19210]: "passive" Feb 18 12:15:01 lithium l2tpd[19210]: "-detach" Feb 18 12:15:01 lithium l2tpd[19210]: "192.168.2.203:192.168.2.204" Feb 18 12:15:01 lithium l2tpd[19210]: "refuse-pap" Feb 18 12:15:01 lithium l2tpd[19210]: "auth" Feb 18 12:15:01 lithium l2tpd[19210]: "require-chap" Feb 18 12:15:01 lithium l2tpd[19210]: "name" Feb 18 12:15:01 lithium l2tpd[19210]: "Test" Feb 18 12:15:01 lithium l2tpd[19210]: "debug" Feb 18 12:15:01 lithium l2tpd[19210]: "file" Feb 18 12:15:01 lithium l2tpd[19210]: "/etc/ppp/options.l2tpd" Feb 18 12:15:01 lithium l2tpd[19210]: "/dev/ttyp0" Feb 18 12:15:01 lithium l2tpd[19210]: Feb 18 12:15:01 lithium pppd[17661]: pppd options in effect: Feb 18 12:15:01 lithium l2tpd[19210]: control_finish: Call established with xx.xx.xx.xx, Local: 45349, Remote: 4736, Serial: 1 Feb 18 12:15:01 lithium pppd[17661]: debug debug^I^I# (from /etc/ppp/options.l2tpd) Feb 18 12:15:01 lithium pppd[17661]: -detach^I^I# (from command line) Feb 18 12:15:01 lithium pppd[17661]: idle 1800^I^I# (from /etc/ppp/options.l2tpd) Feb 18 12:15:01 lithium pppd[17661]: nologfd^I^I# (from /etc/ppp/options.l2tpd) Feb 18 12:15:01 lithium pppd[17661]: connect-delay 5000^I^I# (from /etc/ppp/options.l2tpd) Feb 18 12:15:01 lithium pppd[17661]: dump^I^I# (from /etc/ppp/options.l2tpd) Feb 18 12:15:01 lithium pppd[17661]: auth^I^I# (from /etc/ppp/options.l2tpd) Feb 18 12:15:01 lithium pppd[17661]: refuse-pap^I^I# (from /etc/ppp/options.l2tpd) Feb 18 12:15:01 lithium pppd[17661]: refuse-chap^I^I# (from /etc/ppp/options.l2tpd) Feb 18 12:15:01 lithium pppd[17661]: refuse-mschap^I^I# (from /etc/ppp/options.l2tpd) Feb 18 12:15:01 lithium pppd[17661]: name hostname^I^I# (from /etc/ppp/options.l2tpd) Feb 18 12:15:01 lithium pppd[17661]: /dev/ttyp0^I^I# (from command line) Feb 18 12:15:01 lithium pppd[17661]: lock^I^I# (from /etc/ppp/options.l2tpd) Feb 18 12:15:01 lithium pppd[17661]: crtscts^I^I# (from /etc/ppp/options.l2tpd) Feb 18 12:15:01 lithium pppd[17661]: modem^I^I# (from /etc/ppp/options) Feb 18 12:15:01 lithium pppd[17661]: asyncmap 0^I^I# (from /etc/ppp/options) Feb 18 12:15:01 lithium pppd[17661]: mru 1400^I^I# (from /etc/ppp/options.l2tpd) Feb 18 12:15:01 lithium pppd[17661]: mtu 1400^I^I# (from /etc/ppp/options.l2tpd) Feb 18 12:15:01 lithium pppd[17661]: passive^I^I# (from command line) Feb 18 12:15:01 lithium pppd[17661]: lcp-echo-failure 1^I^I# (from /etc/ppp/options.l2tpd) Feb 18 12:15:01 lithium pppd[17661]: lcp-echo-interval 2^I^I# (from /etc/ppp/options.l2tpd) Feb 18 12:15:01 lithium pppd[17661]: hide-password^I^I# (from /etc/ppp/options) Feb 18 12:15:01 lithium pppd[17661]: ms-dns xxx # [don't know how to print value]^I^I# (from /etc/ppp/options.l2tpd) Feb 18 12:15:01 lithium pppd[17661]: proxyarp^I^I# (from /etc/ppp/options) Feb 18 12:15:01 lithium pppd[17661]: netmask 255.255.255.0^I^I# (from /etc/ppp/options.l2tpd) Feb 18 12:15:01 lithium pppd[17661]: 192.168.2.203:192.168.2.204^I^I# (from command line) Feb 18 12:15:01 lithium pppd[17661]: nobsdcomp^I^I# (from /etc/ppp/options.l2tpd) Feb 18 12:15:01 lithium pppd[17661]: noipx^I^I# (from /etc/ppp/options) Feb 18 12:15:01 lithium pppd[17661]: pppd 2.4.2 started by root, uid 0 Feb 18 12:15:01 lithium pppd[17661]: using channel 86 Feb 18 12:15:01 lithium pppd[17661]: Using interface ppp0 Feb 18 12:15:01 lithium pppd[17661]: Connect: ppp0 <--> /dev/ttyp0 Feb 18 12:15:01 lithium pppd[17661]: sent [LCP ConfReq id=0x1 <mru 1400> <asyncmap 0x0> <auth chap MD5> <magic 0xf0ca4731> <pcomp> <accomp>] Feb 18 12:15:01 lithium pppd[17661]: rcvd [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x7b4b2e1a> <pcomp> <accomp>] Feb 18 12:15:01 lithium pppd[17661]: sent [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0x7b4b2e1a> <pcomp> <accomp>] Feb 18 12:15:01 lithium pppd[17661]: rcvd [LCP ConfAck id=0x1 <mru 1400> <asyncmap 0x0> <auth chap MD5> <magic 0xf0ca4731> <pcomp> <accomp>] Feb 18 12:15:01 lithium pppd[17661]: sent [LCP EchoReq id=0x0 magic=0xf0ca4731] Feb 18 12:15:01 lithium pppd[17661]: sent [CHAP Challenge id=0xaa <d52bdf0bf3f1e41052fb3f5df005e4fa69>, name = "hostname"] Feb 18 12:15:01 lithium pppd[17661]: rcvd [LCP EchoReq id=0x0 magic=0x7b4b2e1a] Feb 18 12:15:01 lithium pppd[17661]: sent [LCP EchoRep id=0x0 magic=0xf0ca4731] Feb 18 12:15:01 lithium pppd[17661]: rcvd [LCP EchoRep id=0x0 magic=0x7b4b2e1a] Feb 18 12:15:01 lithium pppd[17661]: rcvd [CHAP Response id=0xaa <f368a8803b72e0756a7d8bc6b8d8106d>, name = "xxxxxxx"] Feb 18 12:15:01 lithium pppd[17661]: sent [CHAP Success id=0xaa "Access granted"] Feb 18 12:15:01 lithium pppd[17661]: sent [CCP ConfReq id=0x1 <deflate 15> <deflate(old#) 15>] Feb 18 12:15:01 lithium pppd[17661]: sent [IPCP ConfReq id=0x1 <compress VJ 0f 01> <addr 192.168.2.203>] Feb 18 12:15:01 lithium pppd[17661]: rcvd [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns3 0.0.0.0>] Feb 18 12:15:01 lithium pppd[17661]: sent [IPCP ConfNak id=0x1 <addr 192.168.2.204> <ms-dns1 192.168.2.101> <ms-dns3 128.32.136.9>] Feb 18 12:15:01 lithium pppd[17661]: rcvd [IPV6CP ConfReq id=0x1 <addr fe80::020d:93ff:fe56:5742>] Feb 18 12:15:01 lithium pppd[17661]: Unsupported protocol 0x8057 received Feb 18 12:15:01 lithium pppd[17661]: sent [LCP ProtRej id=0x2 80 57 01 01 00 0e 01 0a 02 0d 93 ff fe 56 57 42] Feb 18 12:15:01 lithium pppd[17661]: rcvd [proto=0x8235] 01 01 00 10 01 06 00 00 00 01 02 06 00 00 00 01 Feb 18 12:15:01 lithium pppd[17661]: Unsupported protocol 0x8235 received Feb 18 12:15:01 lithium pppd[17661]: sent [LCP ProtRej id=0x3 82 35 01 01 00 10 01 06 00 00 00 01 02 06 00 00 00 01] Feb 18 12:15:01 lithium pppd[17661]: rcvd [LCP ProtRej id=0x2 80 fd 01 01 00 0c 1a 04 78 00 18 04 78 00] Feb 18 12:15:01 lithium pppd[17661]: rcvd [IPCP ConfRej id=0x1 <compress VJ 0f 01>] Feb 18 12:15:01 lithium pppd[17661]: sent [IPCP ConfReq id=0x2 <addr 192.168.2.203>] Feb 18 12:15:01 lithium pppd[17661]: rcvd [IPCP ConfReq id=0x2 <addr 192.168.2.204> <ms-dns1 192.168.2.101> <ms-dns3 128.32.136.9>] Feb 18 12:15:01 lithium pppd[17661]: sent [IPCP ConfAck id=0x2 <addr 192.168.2.204> <ms-dns1 192.168.2.101> <ms-dns3 128.32.136.9>] Feb 18 12:15:02 lithium pppd[17661]: rcvd [IPCP ConfAck id=0x2 <addr 192.168.2.203>] Feb 18 12:15:02 lithium pppd[17661]: found interface eth0 for proxy arp Feb 18 12:15:02 lithium pppd[17661]: local IP address 192.168.2.203 Feb 18 12:15:02 lithium pppd[17661]: remote IP address 192.168.2.204 Feb 18 12:15:02 lithium pppd[17661]: Script /etc/ppp/ip-up started (pid 17672) Feb 18 12:15:02 lithium postfix/master[27671]: reload configuration Feb 18 12:15:02 lithium pppd[17661]: Script /etc/ppp/ip-up finished (pid 17672), status = 0x0 Feb 18 12:15:03 lithium pppd[17661]: sent [LCP EchoReq id=0x1 magic=0xf0ca4731] Feb 18 12:15:03 lithium pppd[17661]: rcvd [LCP EchoRep id=0x1 magic=0x7b4b2e1a] ... Feb 18 12:15:29 lithium pppd[17661]: sent [LCP EchoReq id=0xe magic=0xf0ca4731] Feb 18 12:15:30 lithium pppd[17661]: rcvd [LCP TermReq id=0x3 "User request"] Feb 18 12:15:30 lithium pppd[17661]: LCP terminated by peer (User request) Feb 18 12:15:30 lithium pppd[17661]: Connect time 0.5 minutes. Feb 18 12:15:30 lithium pppd[17661]: Sent 837277 bytes, received 19586 bytes. Feb 18 12:15:30 lithium pppd[17661]: Script /etc/ppp/ip-down started (pid 17821) Feb 18 12:15:30 lithium pppd[17661]: sent [LCP TermAck id=0x3] Feb 18 12:15:30 lithium postfix/master[27671]: reload configuration Feb 18 12:15:30 lithium pppd[17661]: Script /etc/ppp/ip-down finished (pid 17821), status = 0x0 Feb 18 12:15:30 lithium l2tpd[19210]: check_control: control, cid = 4736, Ns = 4, Nr = 2 Feb 18 12:15:30 lithium l2tpd[19210]: handle_avps: handling avp's for tunnel 31427, call 45349 Feb 18 12:15:30 lithium l2tpd[19210]: message_type_avp: message type 14 (Call-Disconnect-Notify) Feb 18 12:15:30 lithium l2tpd[19210]: assigned_session_avp: assigned session id: 4736 Feb 18 12:15:30 lithium l2tpd[19210]: result_code_avp: peer closing for reason 3 (Call disconnected for administrative reasons), error = 0 () Feb 18 12:15:30 lithium l2tpd[19210]: control_finish: Peer tried to disconnect without specifying call ID Feb 18 12:15:30 lithium l2tpd[19210]: check_control: control, cid = 0, Ns = 5, Nr = 2 Feb 18 12:15:30 lithium l2tpd[19210]: handle_avps: handling avp's for tunnel 31427, call 33679 Feb 18 12:15:30 lithium l2tpd[19210]: message_type_avp: message type 4 (Stop-Control-Connection-Notification) Feb 18 12:15:30 lithium l2tpd[19210]: assigned_tunnel_avp: using peer's tunnel 102 Feb 18 12:15:30 lithium l2tpd[19210]: result_code_avp: peer closing for reason 1 (General request to clear control connection), error = 0 () Feb 18 12:15:30 lithium l2tpd[19210]: control_finish: Connection closed to xx.xx.xx.xx, port 50902 (), Local: 31427, Remote: 102 The log for a successful run is identical except for, at the end: Feb 18 12:17:12 lithium pppd[18316]: Terminating on signal 15. Feb 18 12:17:12 lithium pppd[18316]: Modem hangup Feb 18 12:17:12 lithium pppd[18316]: Connection terminated. Feb 18 12:17:12 lithium pppd[18316]: Exit. Ben
