Attachment 947289 Details for Bug 1153315 – Log messages from VPN connection attempt

Log messages from VPN connection attempt

xl2tp-pppd-messages.txt (text/plain), 26.30 KB, created by Alan Stern on 2014-10-15 18:38:22 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Alan Stern

Created: 2014-10-15 18:38:22 UTC

Size: 26.30 KB

patch

obsolete

>Oct 13 17:09:55 saphir systemd: Starting Internet Key Exchange (IKE) Protocol Daemon for IPsec...
>Oct 13 17:09:56 saphir systemd: Started Internet Key Exchange (IKE) Protocol Daemon for IPsec.
>Oct 13 17:09:56 saphir sh: pluto: warning: chdir("/var/run/pluto/") to dumpdir failed (2: No such file or directory)
>Oct 13 17:09:56 saphir pluto: pluto: warning: chdir("/var/run/pluto/") to dumpdir failed (2: No such file or directory)
>Oct 13 17:10:25 saphir NetworkManager[439]: <info> Starting VPN service 'l2tp'...
>Oct 13 17:10:25 saphir NetworkManager[439]: <info> VPN service 'l2tp' started (org.freedesktop.NetworkManager.l2tp), PID 2573
>Oct 13 17:10:25 saphir NetworkManager: ** Message: nm-l2tp-service (version 0.9.8.5) starting...
>Oct 13 17:10:25 saphir NetworkManager[439]: <info> VPN service 'l2tp' appeared; activating connections
>Oct 13 17:10:25 saphir NetworkManager[439]: <info> VPN plugin state changed: init (1)
>Oct 13 17:10:25 saphir NetworkManager: connection
>Oct 13 17:10:25 saphir NetworkManager: name : "connection"
>Oct 13 17:10:25 saphir NetworkManager: id : "Rowland" (s)
>Oct 13 17:10:25 saphir NetworkManager: uuid : "47d9c44e-50d5-4f0f-b70c-a433be6fb822" (s)
>Oct 13 17:10:26 saphir NetworkManager: interface-name : NULL (sd)
>Oct 13 17:10:26 saphir NetworkManager: type : "vpn" (s)
>Oct 13 17:10:26 saphir NetworkManager: permissions :  (sd)
>Oct 13 17:10:26 saphir NetworkManager: autoconnect : FALSE (s)
>Oct 13 17:10:26 saphir NetworkManager: timestamp : 1412023686 (s)
>Oct 13 17:10:26 saphir NetworkManager: read-only : FALSE (sd)
>Oct 13 17:10:26 saphir NetworkManager: zone : NULL (sd)
>Oct 13 17:10:26 saphir NetworkManager: master : NULL (sd)
>Oct 13 17:10:26 saphir NetworkManager: slave-type : NULL (sd)
>Oct 13 17:10:26 saphir NetworkManager: secondaries :  (sd)
>Oct 13 17:10:26 saphir NetworkManager: gateway-ping-timeout : 0 (sd)
>Oct 13 17:10:26 saphir NetworkManager: vpn
>Oct 13 17:10:26 saphir NetworkManager: name : "vpn"
>Oct 13 17:10:26 saphir NetworkManager: service-type : "org.freedesktop.NetworkManager.l2tp" (s)
>Oct 13 17:10:26 saphir NetworkManager: user-name : "stern" (s)
>Oct 13 17:10:26 saphir NetworkManager: data : lcp-echo-interval=30,password-flags=1,ipsec-psk=********,user=stern,refuse-eap=yes,refuse-chap=yes,ipsec-enabled=yes,lcp-echo-failure=5,gateway=vpn.rowland.org,refuse-mschap=yes (s)
>Oct 13 17:10:26 saphir NetworkManager: secrets : password=******** (s)
>Oct 13 17:10:26 saphir NetworkManager: ipv6
>Oct 13 17:10:26 saphir NetworkManager: name : "ipv6"
>Oct 13 17:10:26 saphir NetworkManager: method : "auto" (s)
>Oct 13 17:10:26 saphir NetworkManager: dhcp-hostname : NULL (sd)
>Oct 13 17:10:26 saphir NetworkManager: dns :  (s)
>Oct 13 17:10:26 saphir NetworkManager: dns-search :  (sd)
>Oct 13 17:10:26 saphir NetworkManager: addresses :  (s)
>Oct 13 17:10:26 saphir NetworkManager: routes :  (s)
>Oct 13 17:10:26 saphir NetworkManager: ignore-auto-routes : FALSE (sd)
>Oct 13 17:10:26 saphir NetworkManager: ignore-auto-dns : FALSE (sd)
>Oct 13 17:10:26 saphir NetworkManager: never-default : FALSE (sd)
>Oct 13 17:10:26 saphir NetworkManager: may-fail : TRUE (sd)
>Oct 13 17:10:26 saphir NetworkManager: ip6-privacy : -1 (sd)
>Oct 13 17:10:26 saphir NetworkManager: ipv4
>Oct 13 17:10:26 saphir NetworkManager: name : "ipv4"
>Oct 13 17:10:26 saphir NetworkManager: method : "auto" (s)
>Oct 13 17:10:26 saphir NetworkManager: dns :  (s)
>Oct 13 17:10:26 saphir NetworkManager: dns-search :  (sd)
>Oct 13 17:10:26 saphir NetworkManager: addresses :  (s)
>Oct 13 17:10:26 saphir NetworkManager: routes :  (s)
>Oct 13 17:10:26 saphir NetworkManager: ignore-auto-routes : FALSE (sd)
>Oct 13 17:10:26 saphir NetworkManager: ignore-auto-dns : FALSE (sd)
>Oct 13 17:10:26 saphir NetworkManager: dhcp-client-id : NULL (sd)
>Oct 13 17:10:26 saphir NetworkManager: dhcp-send-hostname : TRUE (sd)
>Oct 13 17:10:26 saphir NetworkManager: dhcp-hostname : NULL (sd)
>Oct 13 17:10:26 saphir NetworkManager: never-default : FALSE (sd)
>Oct 13 17:10:26 saphir NetworkManager: may-fail : TRUE (sd)
>Oct 13 17:10:26 saphir NetworkManager[439]: <info> VPN plugin state changed: starting (3)
>Oct 13 17:10:26 saphir NetworkManager: ** Message: Use '140.247.233.37' as a gateway
>Oct 13 17:10:26 saphir NetworkManager: ** Message: Check port 1701
>Oct 13 17:10:26 saphir NetworkManager: ** Message: ipsec enable flag: yes
>Oct 13 17:10:26 saphir NetworkManager: ** Message: starting ipsec
>Oct 13 17:10:26 saphir NetworkManager: 002 listening for IKE messages
>Oct 13 17:10:26 saphir NetworkManager: 002 loading secrets from "/etc/ipsec.secrets"
>Oct 13 17:10:26 saphir NetworkManager: 002 no secrets filename matched "/etc/ipsec.d/*.secrets"
>Oct 13 17:10:26 saphir NetworkManager: ** (nm-l2tp-service:2573): WARNING **: ipsec whack --listen -> 0
>Oct 13 17:10:26 saphir NetworkManager: 002 loading secrets from "/etc/ipsec.secrets"
>Oct 13 17:10:26 saphir NetworkManager: debugging mode enabled
>Oct 13 17:10:26 saphir NetworkManager: end of file /var/run/nm-ipsec-l2tp.2573/ipsec.conf
>Oct 13 17:10:26 saphir NetworkManager: Warning: ignored obsolete keyword 'nat_traversal'
>Oct 13 17:10:26 saphir NetworkManager: Loading conn nm-ipsec-l2tpd-2573
>Oct 13 17:10:26 saphir NetworkManager: starter: case KH_DEFAULTROUTE: empty
>Oct 13 17:10:26 saphir NetworkManager: conn: "nm-ipsec-l2tpd-2573" loopback=0
>Oct 13 17:10:26 saphir NetworkManager: conn: "nm-ipsec-l2tpd-2573" labeled_ipsec=0
>Oct 13 17:10:26 saphir NetworkManager: conn: "nm-ipsec-l2tpd-2573" policy_label=(null)
>Oct 13 17:10:26 saphir NetworkManager: conn: "nm-ipsec-l2tpd-2573" modecfgdomain=(null)
>Oct 13 17:10:26 saphir NetworkManager: conn: "nm-ipsec-l2tpd-2573" modecfgbanner=(null)
>Oct 13 17:10:26 saphir NetworkManager: opening file: /var/run/nm-ipsec-l2tp.2573/ipsec.conf
>Oct 13 17:10:26 saphir NetworkManager: loading named conns: nm-ipsec-l2tpd-2573
>Oct 13 17:10:26 saphir NetworkManager: seeking_src = 0, seeking_gateway = 1, has_dst = 1
>Oct 13 17:10:26 saphir NetworkManager: dst  via 192.168.0.1 dev wlan0 src  table 254 (ignored)
>Oct 13 17:10:26 saphir NetworkManager: set nexthop: 192.168.0.1
>Oct 13 17:10:26 saphir NetworkManager: dst 192.168.0.0 via  dev wlan0 src 192.168.0.203 table 254 (ignored)
>Oct 13 17:10:26 saphir NetworkManager: dst 127.0.0.0 via  dev lo src 127.0.0.1 table 255
>Oct 13 17:10:26 saphir NetworkManager: dst 127.0.0.0 via  dev lo src 127.0.0.1 table 255
>Oct 13 17:10:26 saphir NetworkManager: dst 127.0.0.1 via  dev lo src 127.0.0.1 table 255
>Oct 13 17:10:26 saphir NetworkManager: dst 127.255.255.255 via  dev lo src 127.0.0.1 table 255
>Oct 13 17:10:26 saphir NetworkManager: dst 192.168.0.0 via  dev wlan0 src 192.168.0.203 table 255
>Oct 13 17:10:26 saphir NetworkManager: dst 192.168.0.203 via  dev wlan0 src 192.168.0.203 table 255
>Oct 13 17:10:26 saphir NetworkManager: dst 192.168.0.255 via  dev wlan0 src 192.168.0.203 table 255
>Oct 13 17:10:26 saphir NetworkManager: seeking_src = 1, seeking_gateway = 0, has_dst = 1
>Oct 13 17:10:26 saphir NetworkManager: dst 192.168.0.1 via  dev wlan0 src 192.168.0.203 table 254 (ignored)
>Oct 13 17:10:26 saphir NetworkManager: set addr: 192.168.0.203
>Oct 13 17:10:26 saphir NetworkManager: debugging mode enabled
>Oct 13 17:10:26 saphir NetworkManager: end of file /var/run/nm-ipsec-l2tp.2573/ipsec.conf
>Oct 13 17:10:26 saphir NetworkManager: Warning: ignored obsolete keyword 'nat_traversal'
>Oct 13 17:10:26 saphir NetworkManager: Loading conn nm-ipsec-l2tpd-2573
>Oct 13 17:10:26 saphir NetworkManager: starter: case KH_DEFAULTROUTE: empty
>Oct 13 17:10:26 saphir NetworkManager: conn: "nm-ipsec-l2tpd-2573" loopback=0
>Oct 13 17:10:26 saphir NetworkManager: conn: "nm-ipsec-l2tpd-2573" labeled_ipsec=0
>Oct 13 17:10:26 saphir NetworkManager: conn: "nm-ipsec-l2tpd-2573" policy_label=(null)
>Oct 13 17:10:26 saphir NetworkManager: conn: "nm-ipsec-l2tpd-2573" modecfgdomain=(null)
>Oct 13 17:10:26 saphir NetworkManager: conn: "nm-ipsec-l2tpd-2573" modecfgbanner=(null)
>Oct 13 17:10:26 saphir NetworkManager: opening file: /var/run/nm-ipsec-l2tp.2573/ipsec.conf
>Oct 13 17:10:26 saphir NetworkManager: loading named conns: nm-ipsec-l2tpd-2573
>Oct 13 17:10:26 saphir NetworkManager: seeking_src = 0, seeking_gateway = 1, has_dst = 1
>Oct 13 17:10:26 saphir NetworkManager: dst  via 192.168.0.1 dev wlan0 src  table 254 (ignored)
>Oct 13 17:10:26 saphir NetworkManager: set nexthop: 192.168.0.1
>Oct 13 17:10:26 saphir NetworkManager: dst 192.168.0.0 via  dev wlan0 src 192.168.0.203 table 254 (ignored)
>Oct 13 17:10:26 saphir NetworkManager: dst 127.0.0.0 via  dev lo src 127.0.0.1 table 255
>Oct 13 17:10:26 saphir NetworkManager: dst 127.0.0.0 via  dev lo src 127.0.0.1 table 255
>Oct 13 17:10:26 saphir NetworkManager: dst 127.0.0.1 via  dev lo src 127.0.0.1 table 255
>Oct 13 17:10:26 saphir NetworkManager: dst 127.255.255.255 via  dev lo src 127.0.0.1 table 255
>Oct 13 17:10:26 saphir NetworkManager: dst 192.168.0.0 via  dev wlan0 src 192.168.0.203 table 255
>Oct 13 17:10:26 saphir NetworkManager: dst 192.168.0.203 via  dev wlan0 src 192.168.0.203 table 255
>Oct 13 17:10:26 saphir NetworkManager: dst 192.168.0.255 via  dev wlan0 src 192.168.0.203 table 255
>Oct 13 17:10:26 saphir NetworkManager: seeking_src = 1, seeking_gateway = 0, has_dst = 1
>Oct 13 17:10:26 saphir NetworkManager: dst 192.168.0.1 via  dev wlan0 src 192.168.0.203 table 254 (ignored)
>Oct 13 17:10:26 saphir NetworkManager: set addr: 192.168.0.203
>Oct 13 17:10:26 saphir NetworkManager: 002 "nm-ipsec-l2tpd-2573" #1: initiating Main Mode
>Oct 13 17:10:26 saphir NetworkManager: 104 "nm-ipsec-l2tpd-2573" #1: STATE_MAIN_I1: initiate
>Oct 13 17:10:26 saphir NetworkManager: 003 "nm-ipsec-l2tpd-2573" #1: received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02_n]
>Oct 13 17:10:26 saphir NetworkManager: 003 "nm-ipsec-l2tpd-2573" #1: received Vendor ID payload [FRAGMENTATION c0000000]
>Oct 13 17:10:26 saphir NetworkManager: 002 "nm-ipsec-l2tpd-2573" #1: enabling possible NAT-traversal with method draft-ietf-ipsec-nat-t-ike-02/03
>Oct 13 17:10:26 saphir NetworkManager: 002 "nm-ipsec-l2tpd-2573" #1: transition from state STATE_MAIN_I1 to state STATE_MAIN_I2
>Oct 13 17:10:26 saphir NetworkManager: 106 "nm-ipsec-l2tpd-2573" #1: STATE_MAIN_I2: sent MI2, expecting MR2
>Oct 13 17:10:26 saphir NetworkManager: 003 "nm-ipsec-l2tpd-2573" #1: received Vendor ID payload [Cisco-Unity]
>Oct 13 17:10:26 saphir NetworkManager: 003 "nm-ipsec-l2tpd-2573" #1: received Vendor ID payload [XAUTH]
>Oct 13 17:10:26 saphir NetworkManager: 003 "nm-ipsec-l2tpd-2573" #1: ignoring unknown Vendor ID payload [617192cdba35a9f9969ed034345ae8c3]
>Oct 13 17:10:26 saphir NetworkManager: 003 "nm-ipsec-l2tpd-2573" #1: ignoring Vendor ID payload [Cisco VPN 3000 Series]
>Oct 13 17:10:26 saphir NetworkManager: 003 "nm-ipsec-l2tpd-2573" #1: NAT-Traversal: Result using draft-ietf-ipsec-nat-t-ike-02/03 sender port 500: I am behind NAT+peer behind NAT
>Oct 13 17:10:26 saphir NetworkManager: 002 "nm-ipsec-l2tpd-2573" #1: transition from state STATE_MAIN_I2 to state STATE_MAIN_I3
>Oct 13 17:10:26 saphir NetworkManager: 108 "nm-ipsec-l2tpd-2573" #1: STATE_MAIN_I3: sent MI3, expecting MR3
>Oct 13 17:10:26 saphir NetworkManager: 003 "nm-ipsec-l2tpd-2573" #1: received Vendor ID payload [Dead Peer Detection]
>Oct 13 17:10:26 saphir NetworkManager: 002 "nm-ipsec-l2tpd-2573" #1: Main mode peer ID is ID_IPV4_ADDR: '140.247.233.37'
>Oct 13 17:10:26 saphir NetworkManager: 002 "nm-ipsec-l2tpd-2573" #1: transition from state STATE_MAIN_I3 to state STATE_MAIN_I4
>Oct 13 17:10:26 saphir NetworkManager: 004 "nm-ipsec-l2tpd-2573" #1: STATE_MAIN_I4: ISAKMP SA established {auth=PRESHARED_KEY cipher=oakley_3des_cbc_192 integ=sha group=MODP1024}
>Oct 13 17:10:26 saphir NetworkManager: 002 "nm-ipsec-l2tpd-2573" #2: initiating Quick Mode PSK+ENCRYPT+UP+IKEV2_ALLOW+SAREF_TRACK+IKE_FRAG_ALLOW {using isakmp#1 msgid:c1aecb3b proposal=3DES(3)_000-SHA1(2)_000 pfsgroup=no-pfs}
>Oct 13 17:10:26 saphir NetworkManager: 117 "nm-ipsec-l2tpd-2573" #2: STATE_QUICK_I1: initiate
>Oct 13 17:10:26 saphir NetworkManager: 003 "nm-ipsec-l2tpd-2573" #2: our client subnet returned doesn't match my proposal - us:192.168.0.203/32 vs them:50.189.57.27/32
>Oct 13 17:10:26 saphir NetworkManager: 003 "nm-ipsec-l2tpd-2573" #2: Allowing questionable proposal anyway [ALLOW_MICROSOFT_BAD_PROPOSAL]
>Oct 13 17:10:26 saphir NetworkManager: 002 "nm-ipsec-l2tpd-2573" #2: transition from state STATE_QUICK_I1 to state STATE_QUICK_I2
>Oct 13 17:10:26 saphir NetworkManager: 004 "nm-ipsec-l2tpd-2573" #2: STATE_QUICK_I2: sent QI2, IPsec SA established transport mode {ESP/NAT=>0xf25207c6 <0x2efdde0d xfrm=3DES_0-HMAC_SHA1 NATOA=140.247.233.37 NATD=140.247.233.37:4500 DPD=passive}
>Oct 13 17:10:26 saphir NetworkManager: 002 forgetting secrets
>Oct 13 17:10:26 saphir NetworkManager: 002 loading secrets from "/etc/ipsec.secrets"
>Oct 13 17:10:26 saphir NetworkManager: 002 no secrets filename matched "/etc/ipsec.d/*.secrets"
>Oct 13 17:10:26 saphir NetworkManager: ** Message: ipsec ready for action
>Oct 13 17:10:27 saphir NetworkManager: ** Message: xl2tpd started with pid 2616
>Oct 13 17:10:27 saphir NetworkManager[439]: <info> VPN connection 'Rowland' (Connect) reply received.
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: setsockopt recvref[30]: Protocol not available
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: Using l2tp kernel support.
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: xl2tpd version xl2tpd-1.3.6 started on saphir.localdomain PID:2616
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: Written by Mark Spencer, Copyright (C) 1998, Adtran, Inc.
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: Forked by Scott Balmos and David Stipp, (C) 2001
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: Inherited by Jeff McAdams, (C) 2002
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: Forked again by Xelerance (www.xelerance.com) (C) 2006
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: Listening on IP address 0.0.0.0, port 1701
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: get_call: allocating new tunnel for host 140.247.233.37, port 1701.
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: Connecting to host 140.247.233.37, port 1701
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: control_finish: message type is (null)(0).  Tunnel is 0, call is 0.
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: control_finish: sending SCCRQ
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: network_thread: recv packet from 140.247.233.37, size = 106, tunnel = 33716, call = 0 ref=0 refhim=0
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: handle_avps: handling avp's for tunnel 33716, call 0
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: message_type_avp: message type 2 (Start-Control-Connection-Reply)
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: protocol_version_avp: peer is using version 1, revision 0.
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: framing_caps_avp: supported peer frames: async sync
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: bearer_caps_avp: supported peer bearers: analog digital
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: firmware_rev_avp: peer reports firmware version 4384 (0x1120)
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: hostname_avp: peer reports hostname 'vpn'
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: vendor_avp: peer reports vendor 'Cisco Systems, Inc.'
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: assigned_tunnel_avp: using peer's tunnel 147
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: receive_window_size_avp: peer wants RWS of 16.  Will use flow control.
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: control_finish: message type is Start-Control-Connection-Reply(2).  Tunnel is 147, call is 0.
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: control_finish: sending SCCCN
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: Connection established to 140.247.233.37, 1701.  Local: 33716, Remote: 147 (ref=0/0).
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: Calling on tunnel 33716
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: control_finish: message type is (null)(0).  Tunnel is 147, call is 0.
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: control_finish: sending ICRQ
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: network_thread: recv packet from 140.247.233.37, size = 12, tunnel = 33716, call = 0 ref=0 refhim=0
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: network_thread: recv packet from 140.247.233.37, size = 28, tunnel = 33716, call = 27391 ref=0 refhim=0
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: handle_avps: handling avp's for tunnel 33716, call 27391
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: message_type_avp: message type 11 (Incoming-Call-Reply)
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: assigned_call_avp: using peer's call 147
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: control_finish: message type is Incoming-Call-Reply(11).  Tunnel is 147, call is 147.
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: control_finish: Sending ICCN
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: Call established with 140.247.233.37, Local: 27391, Remote: 147, Serial: 1 (ref=0/0)
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: network_thread: recv packet from 140.247.233.37, size = 12, tunnel = 33716, call = 27391 ref=0 refhim=0
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: network_thread: recv packet from 140.247.233.37, size = 36, tunnel = 33716, call = 27391 ref=0 refhim=0
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: handle_avps: handling avp's for tunnel 33716, call 27391
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: message_type_avp: message type 16 (Set-Link-Info)
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: ignore_avp : Ignoring AVP
>Oct 13 17:10:27 saphir NetworkManager: xl2tpd[2616]: control_finish: message type is Set-Link-Info(16).  Tunnel is 147, call is 147.
>Oct 13 17:10:27 saphir pppd[2618]: Plugin /usr/lib/pppd/2.4.5/nm-l2tp-pppd-plugin.so loaded.
>Oct 13 17:10:27 saphir NetworkManager: ** Message: nm-l2tp-ppp-plugin: (plugin_init): initializing
>Oct 13 17:10:27 saphir pppd[2618]: Plugin pppol2tp.so loaded.
>Oct 13 17:10:27 saphir pppd[2618]: pppd 2.4.5 started by root, uid 0
>Oct 13 17:10:27 saphir NetworkManager: ** Message: nm-l2tp-ppp-plugin: (nm_phasechange): status 3 / phase 'serial connection'
>Oct 13 17:10:27 saphir NetworkManager: ** Message: nm-l2tp-ppp-plugin: (nm_phasechange): status 5 / phase 'establish'
>Oct 13 17:10:27 saphir pppd[2618]: Using interface ppp0
>Oct 13 17:10:27 saphir pppd[2618]: Connect: ppp0 <-->
>Oct 13 17:10:27 saphir systemd-sysctl: Overwriting earlier assignment of kernel/sysrq in file '/etc/sysctl.d/sysrq.conf'.
>Oct 13 17:10:27 saphir NetworkManager: ** Message: nm-l2tp-ppp-plugin: (nm_phasechange): status 6 / phase 'authenticate'
>Oct 13 17:10:27 saphir NetworkManager: ** Message: nm-l2tp-ppp-plugin: (get_credentials): passwd-hook, requesting credentials...
>Oct 13 17:10:27 saphir NetworkManager: ** Message: nm-l2tp-ppp-plugin: (get_credentials): got credentials from NetworkManager-l2tp
>Oct 13 17:10:27 saphir pppd[2618]: CHAP authentication succeeded
>Oct 13 17:10:27 saphir pppd[2618]: kernel does not support PPP filtering
>Oct 13 17:10:27 saphir NetworkManager: ** Message: nm-l2tp-ppp-plugin: (nm_phasechange): status 8 / phase 'network'
>Oct 13 17:10:27 saphir NetworkManager[439]: <info> (ppp0): new Generic device (driver: 'unknown' ifindex: 4)
>Oct 13 17:10:27 saphir NetworkManager[439]: <info> (ppp0): exported as /org/freedesktop/NetworkManager/Devices/3
>Oct 13 17:10:27 saphir NetworkManager[439]: <info> (ppp0): No existing connection detected.
>Oct 13 17:10:28 saphir NetworkManager: xl2tpd[2616]: network_thread: select timeout
>Oct 13 17:10:28 saphir NetworkManager: xl2tpd[2616]: network_thread: select timeout
>Oct 13 17:10:28 saphir NetworkManager: xl2tpd[2616]: network_thread: select timeout
>Oct 13 17:10:28 saphir NetworkManager: xl2tpd[2616]: network_thread: select timeout
>Oct 13 17:10:30 saphir pppd[2618]: local  IP address 10.170.30.1
>Oct 13 17:10:30 saphir pppd[2618]: remote IP address 140.247.233.37
>Oct 13 17:10:30 saphir pppd[2618]: primary   DNS address 10.160.0.2
>Oct 13 17:10:30 saphir pppd[2618]: secondary DNS address 10.160.0.3
>Oct 13 17:10:30 saphir NetworkManager: ** Message: nm-l2tp-ppp-plugin: (nm_phasechange): status 9 / phase 'running'
>Oct 13 17:10:30 saphir NetworkManager: ** Message: nm-l2tp-ppp-plugin: (nm_ip_up): ip-up event
>Oct 13 17:10:30 saphir NetworkManager: ** Message: nm-l2tp-ppp-plugin: (nm_ip_up): sending Ip4Config to NetworkManager-l2tp...
>Oct 13 17:10:30 saphir NetworkManager: ** Message: L2TP service (IP Config Get) reply received.
>Oct 13 17:10:30 saphir NetworkManager[439]: <info> VPN connection 'Rowland' (IP4 Config Get) reply received from old-style plugin.
>Oct 13 17:10:30 saphir NetworkManager[439]: <info> VPN Gateway: 140.247.233.37
>Oct 13 17:10:30 saphir NetworkManager[439]: <info> Tunnel Device: ppp0
>Oct 13 17:10:30 saphir NetworkManager[439]: <info> IPv4 configuration:
>Oct 13 17:10:30 saphir NetworkManager[439]: <info>   Internal Address: 10.170.30.1
>Oct 13 17:10:30 saphir NetworkManager[439]: <info>   Internal Prefix: 32
>Oct 13 17:10:30 saphir NetworkManager[439]: <info>   Internal Point-to-Point Address: 140.247.233.37
>Oct 13 17:10:30 saphir NetworkManager[439]: <info>   Maximum Segment Size (MSS): 0
>Oct 13 17:10:30 saphir NetworkManager[439]: <info>   Forbid Default Route: no
>Oct 13 17:10:30 saphir NetworkManager[439]: <info>   Internal DNS: 10.160.0.2
>Oct 13 17:10:30 saphir NetworkManager[439]: <info>   Internal DNS: 10.160.0.3
>Oct 13 17:10:30 saphir NetworkManager[439]: <info>   DNS Domain: '(none)'
>Oct 13 17:10:30 saphir NetworkManager[439]: <info> No IPv6 configuration
>Oct 13 17:10:30 saphir NetworkManager[439]: <info> VPN connection 'Rowland' (IP Config Get) complete.
>Oct 13 17:10:30 saphir NetworkManager[439]: <info> VPN plugin state changed: started (4)
>Oct 13 17:10:30 saphir dbus[447]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service'
>Oct 13 17:10:30 saphir dbus-daemon: dbus[447]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service'
>Oct 13 17:10:30 saphir systemd: Starting Network Manager Script Dispatcher Service...
>Oct 13 17:10:30 saphir dbus-daemon: dbus[447]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
>Oct 13 17:10:30 saphir dbus[447]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
>Oct 13 17:10:30 saphir systemd: Started Network Manager Script Dispatcher Service.
>Oct 13 17:10:30 saphir systemd: Stopping Sendmail Mail Transport Client...
>Oct 13 17:10:30 saphir systemd: Stopping Sendmail Mail Transport Agent...
>Oct 13 17:10:30 saphir systemd: Starting Sendmail Mail Transport Agent...
>Oct 13 17:10:30 saphir systemd: PID file /run/sendmail.pid not readable (yet?) after start.
>Oct 13 17:10:30 saphir systemd: Started Sendmail Mail Transport Agent.
>Oct 13 17:10:30 saphir systemd: Starting Sendmail Mail Transport Client...
>Oct 13 17:10:30 saphir systemd: Started Sendmail Mail Transport Client.
>Oct 13 17:11:27 saphir NetworkManager: xl2tpd[2616]: network_thread: select timeout
>Oct 13 17:11:28 saphir NetworkManager: xl2tpd[2616]: network_thread: select timeout
>Oct 13 17:11:29 saphir NetworkManager: xl2tpd[2616]: network_thread: select timeout
>Oct 13 17:11:30 saphir NetworkManager: xl2tpd[2616]: network_thread: select timeout
>Oct 13 17:11:31 saphir NetworkManager: xl2tpd[2616]: network_thread: select timeout
>Oct 13 17:11:32 saphir NetworkManager: xl2tpd[2616]: network_thread: select timeout
>Oct 13 17:11:32 saphir NetworkManager: xl2tpd[2616]: Maximum retries exceeded for tunnel 33716.  Closing.
>Oct 13 17:11:32 saphir NetworkManager: xl2tpd[2616]: Connection 147 closed to 140.247.233.37, port 1701 (Timeout)
>Oct 13 17:11:32 saphir NetworkManager: xl2tpd[2616]: network_thread: select returned error 4 (Interrupted system call)
>Oct 13 17:11:32 saphir gnome-session: Gjs-Message: JS LOG: Removing a network device that was not added
>Oct 13 17:11:33 saphir NetworkManager: xl2tpd[2616]: network_thread: select timeout
>Oct 13 17:11:34 saphir NetworkManager: xl2tpd[2616]: network_thread: select timeout
>Oct 13 17:11:35 saphir NetworkManager: xl2tpd[2616]: network_thread: select timeout
>Oct 13 17:11:36 saphir NetworkManager: xl2tpd[2616]: network_thread: select timeout
>Oct 13 17:11:37 saphir NetworkManager: xl2tpd[2616]: network_thread: select timeout
>Oct 13 17:11:37 saphir NetworkManager: xl2tpd[2616]: Unable to deliver closing message for tunnel 33716. Destroying anyway.
>Oct 13 17:11:37 saphir NetworkManager: xl2tpd[2616]: network_thread: select returned error 9 (Bad file descriptor)
>Oct 13 17:11:53 saphir dbus-daemon: dbus[447]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service'
>Oct 13 17:11:53 saphir dbus[447]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service'
>Oct 13 17:11:53 saphir systemd: Starting Network Manager Script Dispatcher Service...
>Oct 13 17:11:53 saphir NetworkManager: ** Message: Terminated l2tp daemon with PID 2616.
>Oct 13 17:11:53 saphir NetworkManager: xl2tpd[2616]: network_thread: select returned error 4 (Interrupted system call)
>Oct 13 17:11:53 saphir NetworkManager: xl2tpd[2616]: death_handler: Fatal signal 15 received
>Oct 13 17:11:53 saphir NetworkManager: ** (nm-l2tp-service:2573): WARNING **: xl2tpd exited with error code 1
>Oct 13 17:11:53 saphir dbus-daemon: dbus[447]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
>Oct 13 17:11:53 saphir dbus[447]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
>Oct 13 17:11:53 saphir systemd: Started Network Manager Script Dispatcher Service.
>Oct 13 17:11:53 saphir systemd: Stopping Sendmail Mail Transport Client...
>Oct 13 17:11:53 saphir systemd: Stopping Sendmail Mail Transport Agent...
>Oct 13 17:11:53 saphir systemd: Starting Sendmail Mail Transport Agent...
>Oct 13 17:11:54 saphir systemd: Started Sendmail Mail Transport Agent.
>Oct 13 17:11:54 saphir systemd: Starting Sendmail Mail Transport Client...
>Oct 13 17:11:54 saphir systemd: Started Sendmail Mail Transport Client.
>Oct 13 17:11:59 saphir NetworkManager[439]: <info> VPN service 'l2tp' disappeared
>Oct 13 17:12:08 saphir systemd: Stopping Internet Key Exchange (IKE) Protocol Daemon for IPsec...
>Oct 13 17:12:08 saphir whack: 002 shutting down
>Oct 13 17:12:08 saphir systemd: Stopped Internet Key Exchange (IKE) Protocol Daemon for IPsec.
>Oct 13 17:14:38 saphir systemd: Starting Cleanup of Temporary Directories...
>Oct 13 17:14:38 saphir systemd: Started Cleanup of Temporary Directories.

Actions: View

Attachments on bug 1153315: 947288 | 947289 | 948191 | 948193 | 948194 | 948195 | 948196 | 948197