search

nm-l2tp / NetworkManager-l2tp

L2TP and L2TP/IPsec support for NetworkManager
GNU General Public License v2.0
486 stars 84 forks source link

handle_packet: bad control packet! #83

Closed GWIian closed 6 years ago

GWIian commented 6 years ago

l2tp vpn connection established normally. but can not work correctly, and will be disconnected about 1 min. OS: Debian sid DE: Gnome3 Debug log:

nm-l2tp[9628] <debug> nm-l2tp-service (version 1.2.10) starting...
nm-l2tp[9628] <debug>  uses default --bus-name "org.freedesktop.NetworkManager.l2tp"
nm-l2tp[9628] <info>  ipsec enable flag: (null)
** Message: 15:38:52.608: Check port 1701
connection
    id : "\346\226\260\345\216\202vpn" (s)
    uuid : "af4e7bf8-fbfb-4f04-b775-0679c7b25082" (s)
    interface-name : NULL (sd)
    type : "vpn" (s)
    permissions : ["user:ian:"] (s)
    autoconnect : FALSE (s)
    autoconnect-priority : 0 (sd)
    autoconnect-retries : -1 (sd)
    timestamp : 1528440475 (s)
    read-only : FALSE (sd)
    zone : NULL (sd)
    master : NULL (sd)
    slave-type : NULL (sd)
    autoconnect-slaves : ((NMSettingConnectionAutoconnectSlaves) NM_SETTING_CONNECTION_AUTOCONNECT_SLAVES_DEFAULT) (sd)
    secondaries : NULL (sd)
    gateway-ping-timeout : 0 (sd)
    metered : ((NMMetered) NM_METERED_UNKNOWN) (sd)
    lldp : -1 (sd)
    stable-id : NULL (sd)
    auth-retries : -1 (sd)

ipv6
    method : "ignore" (s)
    dns : [] (s)
    dns-search : [] (s)
    dns-options : NULL (sd)
    dns-priority : 0 (sd)
    addresses : ((GPtrArray*) 0x55b4275dff80) (s)
    gateway : NULL (sd)
    routes : ((GPtrArray*) 0x55b4275dffa0) (s)
    route-metric : -1 (sd)
    route-table : 0 (sd)
    ignore-auto-routes : FALSE (sd)
    ignore-auto-dns : FALSE (sd)
    dhcp-hostname : NULL (sd)
    dhcp-send-hostname : TRUE (sd)
    never-default : FALSE (sd)
    may-fail : TRUE (sd)
    dad-timeout : -1 (sd)
    dhcp-timeout : 0 (sd)
    ip6-privacy : ((NMSettingIP6ConfigPrivacy) NM_SETTING_IP6_CONFIG_PRIVACY_UNKNOWN) (sd)
    addr-gen-mode : 1 (sd)
    token : NULL (sd)

ipv4
    method : "auto" (s)
    dns : [] (s)
    dns-search : [] (s)
    dns-options : NULL (sd)
    dns-priority : 0 (sd)
    addresses : ((GPtrArray*) 0x55b4275e0060) (s)
    gateway : NULL (sd)
    routes : ((GPtrArray*) 0x55b4275e0080) (s)
    route-metric : -1 (sd)
    route-table : 0 (sd)
    ignore-auto-routes : FALSE (sd)
    ignore-auto-dns : FALSE (sd)
    dhcp-hostname : NULL (sd)
    dhcp-send-hostname : TRUE (sd)
    never-default : FALSE (sd)
    may-fail : TRUE (sd)
    dad-timeout : -1 (sd)
    dhcp-timeout : 0 (sd)
    dhcp-client-id : NULL (sd)
    dhcp-fqdn : NULL (sd)

vpn
    service-type : "org.freedesktop.NetworkManager.l2tp" (s)
    user-name : NULL (sd)
    persistent : FALSE (sd)
    data : ((GHashTable*) 0x7f3eb8007640) (s)
    secrets : ((GHashTable*) 0x7f3eb8006f60) (s)
    timeout : 0 (sd)

proxy
    method : 0 (sd)
    browser-only : FALSE (sd)
    pac-url : NULL (sd)
    pac-script : NULL (sd)

** Message: 15:38:52.610: xl2tpd started with pid 9635
xl2tpd[9635]: Not looking for kernel SAref support.
xl2tpd[9635]: Using l2tp kernel support.
xl2tpd[9635]: xl2tpd version xl2tpd-1.3.12 started on qiuqiu PID:9635
xl2tpd[9635]: Written by Mark Spencer, Copyright (C) 1998, Adtran, Inc.
xl2tpd[9635]: Forked by Scott Balmos and David Stipp, (C) 2001
xl2tpd[9635]: Inherited by Jeff McAdams, (C) 2002
xl2tpd[9635]: Forked again by Xelerance (www.xelerance.com) (C) 2006-2016
xl2tpd[9635]: Listening on IP address 0.0.0.0, port 1701
xl2tpd[9635]: get_call: allocating new tunnel for host 218.75.223.169, port 1701.
xl2tpd[9635]: Connecting to host 218.75.223.169, port 1701
xl2tpd[9635]: control_finish: message type is (null)(0).  Tunnel is 0, call is 0.
xl2tpd[9635]: control_finish: sending SCCRQ
xl2tpd[9635]: message_type_avp: message type 2 (Start-Control-Connection-Reply)
xl2tpd[9635]: protocol_version_avp: peer is using version 1, revision 0.
xl2tpd[9635]: framing_caps_avp: supported peer frames: async sync
xl2tpd[9635]: bearer_caps_avp: supported peer bearers:
xl2tpd[9635]: firmware_rev_avp: peer reports firmware version 1680 (0x0690)
xl2tpd[9635]: hostname_avp: peer reports hostname 'localhost'
xl2tpd[9635]: vendor_avp: peer reports vendor 'xelerance.com'
xl2tpd[9635]: assigned_tunnel_avp: using peer's tunnel 31531
xl2tpd[9635]: receive_window_size_avp: peer wants RWS of 4.  Will use flow control.
xl2tpd[9635]: control_finish: message type is Start-Control-Connection-Reply(2).  Tunnel is 31531, call is 0.
xl2tpd[9635]: control_finish: sending SCCCN
xl2tpd[9635]: Connection established to 218.75.223.169, 1701.  Local: 50099, Remote: 31531 (ref=0/0).
xl2tpd[9635]: Calling on tunnel 50099
xl2tpd[9635]: control_finish: message type is (null)(0).  Tunnel is 31531, call is 0.
xl2tpd[9635]: control_finish: sending ICRQ
xl2tpd[9635]: message_type_avp: message type 11 (Incoming-Call-Reply)
xl2tpd[9635]: assigned_call_avp: using peer's call 16231
xl2tpd[9635]: control_finish: message type is Incoming-Call-Reply(11).  Tunnel is 31531, call is 16231.
xl2tpd[9635]: control_finish: Sending ICCN
xl2tpd[9635]: Call established with 218.75.223.169, Local: 61029, Remote: 16231, Serial: 1 (ref=0/0)
xl2tpd[9635]: start_pppd: I'm running: 
xl2tpd[9635]: "/usr/sbin/pppd" 
xl2tpd[9635]: "plugin" 
xl2tpd[9635]: "pppol2tp.so" 
xl2tpd[9635]: "pppol2tp" 
xl2tpd[9635]: "7" 
xl2tpd[9635]: "passive" 
xl2tpd[9635]: "nodetach" 
xl2tpd[9635]: ":" 
xl2tpd[9635]: "debug" 
xl2tpd[9635]: "file" 
xl2tpd[9635]: "/run/nm-l2tp-ppp-options-af4e7bf8-fbfb-4f04-b775-0679c7b25082" 
xl2tpd[9635]: Can not find tunnel 26626 (refhim=0)
xl2tpd[9635]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 26626 Dumping.
xl2tpd[9635]: Can not find tunnel 26626 (refhim=0)
xl2tpd[9635]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 26626 Dumping.
xl2tpd[9635]: Can not find tunnel 26626 (refhim=0)
xl2tpd[9635]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 26626 Dumping.
xl2tpd[9635]: Can not find tunnel 26626 (refhim=0)
xl2tpd[9635]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 26626 Dumping.
xl2tpd[9635]: Can not find tunnel 26626 (refhim=0)
xl2tpd[9635]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 26626 Dumping.
xl2tpd[9635]: Can not find tunnel 26626 (refhim=0)
xl2tpd[9635]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 26626 Dumping.
xl2tpd[9635]: Can not find tunnel 26626 (refhim=0)
xl2tpd[9635]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 26626 Dumping.
xl2tpd[9635]: Can not find tunnel 26626 (refhim=0)
xl2tpd[9635]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 26626 Dumping.
xl2tpd[9635]: Can not find tunnel 26626 (refhim=0)
xl2tpd[9635]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 26626 Dumping.
xl2tpd[9635]: Can not find tunnel 26626 (refhim=0)
xl2tpd[9635]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 26626 Dumping.
xl2tpd[9635]: Can not find tunnel 26626 (refhim=0)
xl2tpd[9635]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 26626 Dumping.
xl2tpd[9635]: Can not find tunnel 26626 (refhim=0)
xl2tpd[9635]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 26626 Dumping.
xl2tpd[9635]: Can not find tunnel 26626 (refhim=0)
xl2tpd[9635]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 26626 Dumping.
xl2tpd[9635]: Can not find tunnel 26626 (refhim=0)
xl2tpd[9635]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 26626 Dumping.
xl2tpd[9635]: Can not find tunnel 26626 (refhim=0)
xl2tpd[9635]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 26626 Dumping.
xl2tpd[9635]: message_type_avp: message type 6 (Hello)
xl2tpd[9635]: control_finish: message type is Hello(6).  Tunnel is 31531, call is 0.
xl2tpd[9635]: Can not find tunnel 26626 (refhim=0)
xl2tpd[9635]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 26626 Dumping.
xl2tpd[9635]: check_control: Received out of order control packet on tunnel 31531 (got 2, expected 3)
xl2tpd[9635]: handle_packet: bad control packet!
xl2tpd[9635]: network_thread: bad packet
xl2tpd[9635]: Can not find tunnel 26626 (refhim=0)
xl2tpd[9635]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 26626 Dumping.
xl2tpd[9635]: check_control: Received out of order control packet on tunnel 31531 (got 2, expected 3)
xl2tpd[9635]: handle_packet: bad control packet!
xl2tpd[9635]: network_thread: bad packet
xl2tpd[9635]: Can not find tunnel 26626 (refhim=0)
xl2tpd[9635]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 26626 Dumping.
xl2tpd[9635]: check_control: Received out of order control packet on tunnel 31531 (got 2, expected 3)
xl2tpd[9635]: handle_packet: bad control packet!
xl2tpd[9635]: network_thread: bad packet
xl2tpd[9635]: Can not find tunnel 26626 (refhim=0)
xl2tpd[9635]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 26626 Dumping.
xl2tpd[9635]: check_control: Received out of order control packet on tunnel 31531 (got 2, expected 3)
xl2tpd[9635]: handle_packet: bad control packet!
xl2tpd[9635]: network_thread: bad packet
xl2tpd[9635]: Can not find tunnel 26626 (refhim=0)
xl2tpd[9635]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 26626 Dumping.
xl2tpd[9635]: Can not find tunnel 26626 (refhim=0)
xl2tpd[9635]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 26626 Dumping.
xl2tpd[9635]: message_type_avp: message type 6 (Hello)
xl2tpd[9635]: control_finish: message type is Hello(6).  Tunnel is 31531, call is 0.
xl2tpd[9635]: check_control: Received out of order control packet on tunnel 31531 (got 2, expected 4)
xl2tpd[9635]: handle_packet: bad control packet!
xl2tpd[9635]: network_thread: bad packet
xl2tpd[9635]: Can not find tunnel 26626 (refhim=0)
xl2tpd[9635]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 26626 Dumping.
xl2tpd[9635]: check_control: Received out of order control packet on tunnel 31531 (got 3, expected 4)
xl2tpd[9635]: handle_packet: bad control packet!
xl2tpd[9635]: network_thread: bad packet
xl2tpd[9635]: check_control: Received out of order control packet on tunnel 31531 (got 2, expected 4)
xl2tpd[9635]: handle_packet: bad control packet!
xl2tpd[9635]: network_thread: bad packet
xl2tpd[9635]: Can not find tunnel 26626 (refhim=0)
xl2tpd[9635]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 26626 Dumping.
xl2tpd[9635]: check_control: Received out of order control packet on tunnel 31531 (got 3, expected 4)
xl2tpd[9635]: handle_packet: bad control packet!
xl2tpd[9635]: network_thread: bad packet
xl2tpd[9635]: check_control: Received out of order control packet on tunnel 31531 (got 2, expected 4)
xl2tpd[9635]: handle_packet: bad control packet!
xl2tpd[9635]: network_thread: bad packet
xl2tpd[9635]: Can not find tunnel 26626 (refhim=0)
xl2tpd[9635]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 26626 Dumping.
xl2tpd[9635]: check_control: Received out of order control packet on tunnel 31531 (got 3, expected 4)
xl2tpd[9635]: handle_packet: bad control packet!
xl2tpd[9635]: network_thread: bad packet
xl2tpd[9635]: check_control: Received out of order control packet on tunnel 31531 (got 2, expected 4)
xl2tpd[9635]: handle_packet: bad control packet!
xl2tpd[9635]: network_thread: bad packet
xl2tpd[9635]: Can not find tunnel 26626 (refhim=0)
xl2tpd[9635]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 26626 Dumping.
xl2tpd[9635]: check_control: Received out of order control packet on tunnel 31531 (got 3, expected 4)
xl2tpd[9635]: handle_packet: bad control packet!
xl2tpd[9635]: network_thread: bad packet
xl2tpd[9635]: check_control: Received out of order control packet on tunnel 31531 (got 2, expected 4)
xl2tpd[9635]: handle_packet: bad control packet!
xl2tpd[9635]: network_thread: bad packet
xl2tpd[9635]: Can not find tunnel 26626 (refhim=0)
xl2tpd[9635]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 26626 Dumping.
xl2tpd[9635]: check_control: Received out of order control packet on tunnel 31531 (got 3, expected 4)
xl2tpd[9635]: handle_packet: bad control packet!
xl2tpd[9635]: network_thread: bad packet
xl2tpd[9635]: check_control: Received out of order control packet on tunnel 31531 (got 2, expected 4)
xl2tpd[9635]: handle_packet: bad control packet!
xl2tpd[9635]: network_thread: bad packet
xl2tpd[9635]: message_type_avp: message type 6 (Hello)
xl2tpd[9635]: control_finish: message type is Hello(6).  Tunnel is 31531, call is 0.
xl2tpd[9635]: Can not find tunnel 26626 (refhim=0)
xl2tpd[9635]: network_thread: unable to find call or tunnel to handle packet.  call = 0, tunnel = 26626 Dumping.
xl2tpd[9635]: check_control: Received out of order control packet on tunnel 31531 (got 3, expected 5)
xl2tpd[9635]: handle_packet: bad control packet!
xl2tpd[9635]: network_thread: bad packet
xl2tpd[9635]: Maximum retries exceeded for tunnel 50099.  Closing.
xl2tpd[9635]: Terminating pppd: sending TERM signal to pid 9636
xl2tpd[9635]: Connection 31531 closed to 218.75.223.169, port 1701 (Timeout)
nm-l2tp[9628] <info>  Terminated xl2tpd daemon with PID 9635.
xl2tpd[9635]: death_handler: Fatal signal 15 received
nm-l2tp[9628] <warn>  xl2tpd exited with error code 1
dkosovic commented 6 years ago

I suspect it is an issue with xl2tpd not communicating with the pppol2tp kernel module, so could you try a different kernel? Alternatively build xl2tpd with the following line in the xl2tpd Makefile commented out :

OSFLAGS+= -DUSE_KERNEL

I've just upgraded to the latest Debian Sid packages and had to issue sudo apt dist-upgrade to do so as the normal upgrade was complaining about "The following packages have been kept back". Unfortunately I'm not able to reproduce your issue. I was having issue with IPsec not connecting and had to switch from strongswan to libreswan as a workaround.

GWIian commented 6 years ago

It's maybe xl2tpd's issue. I will do more test.