openwrt / packages

Community maintained packages for OpenWrt. Documentation for submitting pull requests is in CONTRIBUTING.md
GNU General Public License v2.0
3.98k stars 3.47k forks source link

L2TP doesn't reconnect #8140

Closed Jeroenleender closed 5 years ago

Jeroenleender commented 5 years ago

Maintainer: @yousong Environment: (RAMIPS, HLKRM04, OpenWrt 18.06.2)

Description:

L2TP VPN won't autoreconnect, if WAN cable gets unplugged and gets plugged back in after you receive the message: "daemon.debug xl2tpd[1062]: Unable to deliver closing message for tunnel 20224. Destroying anyway. in system log" in System Log

Everything is build from the default feeds and updated yesterday. Earlier 18.06.1 had the same issue.

Extra question: Would it be possible to have a default l2tp VPN connection added on firstboot? Would allow for easy configuration when replacing devices is needed by non technician.

yousong commented 5 years ago

hi, @Jeroenleender , I currently do not have the necessary environment to reproduce the issue. Please share with us more content from system log to make more clear the event sequence and context. Thank you

Jeroenleender commented 5 years ago
Thu Feb  7 11:30:52 2019 kern.notice kernel: [    0.000000] Linux version 4.14.96 (jeroen@rm04) (gcc version 7.4.0 (OpenWrt GCC 7.4.0 r9239-f665fb058f)) #0 Wed Jan 30 14:17:23 2019
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.000000] SoC Type: Ralink RT5350 id:1 rev:3
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.000000] bootconsole [early0] enabled
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.000000] CPU0 revision is: 0001964c (MIPS 24KEc)
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.000000] MIPS: machine is HILINK HLK-RM04
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.000000] Determined physical RAM map:
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.000000]  memory: 02000000 @ 00000000 (usable)
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.000000] Initrd not found or empty - disabling initrd
Thu Feb  7 11:30:52 2019 kern.warn kernel: [    0.000000] Primary instruction cache 32kB, VIPT, 4-way, linesize 32 bytes.
Thu Feb  7 11:30:52 2019 kern.warn kernel: [    0.000000] Primary data cache 16kB, 4-way, VIPT, no aliases, linesize 32 bytes
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.000000] Zone ranges:
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.000000]   Normal   [mem 0x0000000000000000-0x0000000001ffffff]
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.000000] Movable zone start for each node
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.000000] Early memory node ranges
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.000000]   node   0: [mem 0x0000000000000000-0x0000000001ffffff]
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x0000000001ffffff]
Thu Feb  7 11:30:52 2019 kern.debug kernel: [    0.000000] On node 0 totalpages: 8192
Thu Feb  7 11:30:52 2019 kern.debug kernel: [    0.000000] free_area_init_node: node 0, pgdat 80394b70, node_mem_map 81000040
Thu Feb  7 11:30:52 2019 kern.debug kernel: [    0.000000]   Normal zone: 64 pages used for memmap
Thu Feb  7 11:30:52 2019 kern.debug kernel: [    0.000000]   Normal zone: 0 pages reserved
Thu Feb  7 11:30:52 2019 kern.debug kernel: [    0.000000]   Normal zone: 8192 pages, LIFO batch:0
Thu Feb  7 11:30:52 2019 kern.notice kernel: [    0.000000] random: get_random_bytes called from 0x8039872c with crng_init=0
Thu Feb  7 11:30:52 2019 kern.debug kernel: [    0.000000] pcpu-alloc: s0 r0 d32768 u32768 alloc=1*32768
Thu Feb  7 11:30:52 2019 kern.debug kernel: [    0.000000] pcpu-alloc: [0] 0
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 8128
Thu Feb  7 11:30:52 2019 kern.notice kernel: [    0.000000] Kernel command line: console=ttyS1,57600 rootfstype=squashfs,jffs2
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.000000] PID hash table entries: 128 (order: -3, 512 bytes)
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.000000] Dentry cache hash table entries: 4096 (order: 2, 16384 bytes)
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.000000] Inode-cache hash table entries: 2048 (order: 1, 8192 bytes)
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.000000] Writing ErrCtl register=0006bbf0
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.000000] Readback ErrCtl register=0006bbf0
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.000000] Memory: 28356K/32768K available (3151K kernel code, 160K rwdata, 360K rodata, 160K init, 195K bss, 4412K reserved, 0K cma-reserved)
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.000000] SLUB: HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.000000] NR_IRQS: 256
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.000000] CPU Clock: 360MHz
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.000000] clocksource: systick: mask: 0xffff max_cycles: 0xffff, max_idle_ns: 583261500 ns
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.000000] systick: running - mult: 214748, shift: 32
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.000000] clocksource: MIPS: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 10618113593 ns
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.000016] sched_clock: 32 bits at 180MHz, resolution 5ns, wraps every 11930464253ns
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.015711] Calibrating delay loop... 239.61 BogoMIPS (lpj=1198080)
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.098024] pid_max: default: 32768 minimum: 301
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.107622] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes)
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.120736] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes)
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.143675] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.163234] futex hash table entries: 256 (order: -1, 3072 bytes)
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.175495] pinctrl core: initialized pinctrl subsystem
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.188676] NET: Registered protocol family 16
Thu Feb  7 11:30:52 2019 kern.warn kernel: [    0.206935] Can't analyze schedule() prologue at 8030fbe4
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.260203] rt2880_gpio 10000600.gpio: registering 22 gpios
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.271349] rt2880_gpio 10000600.gpio: registering 22 irq handlers
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.293394] clocksource: Switched to clocksource MIPS
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.305574] NET: Registered protocol family 2
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.316136] TCP established hash table entries: 1024 (order: 0, 4096 bytes)
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.330025] TCP bind hash table entries: 1024 (order: 0, 4096 bytes)
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.342605] TCP: Hash tables configured (established 1024 bind 1024)
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.355607] UDP hash table entries: 256 (order: 0, 4096 bytes)
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.367246] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes)
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.380234] NET: Registered protocol family 1
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.395745] rt-timer 10000100.timer: maximum frequency is 3662Hz
Thu Feb  7 11:30:52 2019 kern.warn kernel: [    0.409445] Crashlog allocated RAM at address 0x1f00000
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.424604] workingset: timestamp_bits=30 max_order=13 bucket_order=0
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.448284] squashfs: version 4.0 (2009/01/31) Phillip Lougher
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.459886] jffs2: version 2.2 (NAND) (SUMMARY) (LZMA) (RTIME) (CMODE_PRIORITY) (c) 2001-2006 Red Hat, Inc.
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.508644] io scheduler noop registered
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.516425] io scheduler deadline registered (default)
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.528546] gpio-export gpio-export: 2 gpio(s) exported
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.539509] Serial: 8250/16550 driver, 16 ports, IRQ sharing enabled
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.558101] 10000500.uart: ttyS0 at MMIO 0x10000500 (irq = 13, base_baud = 2500000) is a Palmchip BK-3103
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.578458] 10000c00.uartlite: ttyS1 at MMIO 0x10000c00 (irq = 20, base_baud = 2500000) is a Palmchip BK-3103
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.598271] console [ttyS1] enabled
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.612049] bootconsole [early0] disabled
Thu Feb  7 11:30:52 2019 kern.err kernel: [    0.628953] cacheinfo: Failed to find cpu0 device node
Thu Feb  7 11:30:52 2019 kern.warn kernel: [    0.639331] cacheinfo: Unable to detect cache hierarchy for CPU 0
Thu Feb  7 11:30:52 2019 kern.warn kernel: [    0.673211] spi spi0.0: force spi mode3
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.682465] m25p80 spi0.0: mx25l6405d (8192 Kbytes)
Thu Feb  7 11:30:52 2019 kern.notice kernel: [    0.692401] 4 fixed-partitions partitions found on MTD device spi0.0
Thu Feb  7 11:30:52 2019 kern.notice kernel: [    0.705127] Creating 4 MTD partitions on "spi0.0":
Thu Feb  7 11:30:52 2019 kern.notice kernel: [    0.714747] 0x000000000000-0x000000030000 : "u-boot"
Thu Feb  7 11:30:52 2019 kern.notice kernel: [    0.726515] 0x000000030000-0x000000040000 : "u-boot-env"
Thu Feb  7 11:30:52 2019 kern.notice kernel: [    0.739130] 0x000000040000-0x000000050000 : "factory"
Thu Feb  7 11:30:52 2019 kern.notice kernel: [    0.751123] 0x000000050000-0x000000800000 : "firmware"
Thu Feb  7 11:30:52 2019 kern.notice kernel: [    0.771220] 2 uimage-fw partitions found on MTD device firmware
Thu Feb  7 11:30:52 2019 kern.notice kernel: [    0.783165] Creating 2 MTD partitions on "firmware":
Thu Feb  7 11:30:52 2019 kern.notice kernel: [    0.793135] 0x000000000000-0x000000132811 : "kernel"
Thu Feb  7 11:30:52 2019 kern.notice kernel: [    0.805023] 0x000000132811-0x0000007b0000 : "rootfs"
Thu Feb  7 11:30:52 2019 kern.notice kernel: [    0.816800] mtd: device 5 (rootfs) set to be root filesystem
Thu Feb  7 11:30:52 2019 kern.notice kernel: [    0.832284] 1 squashfs-split partitions found on MTD device rootfs
Thu Feb  7 11:30:52 2019 kern.notice kernel: [    0.844779] 0x000000566000-0x0000007b0000 : "rootfs_data"
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.858358] libphy: Fixed MDIO Bus: probed
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.875569] rt3050-esw 10110000.esw: link changed 0x00
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.888967] mtk_soc_eth 10100000.ethernet eth0: mediatek frame engine at 0xb0100000, irq 5
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.906527] rt2880_wdt 10000120.watchdog: Initialized
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.917811] NET: Registered protocol family 17
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.927006] bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this.
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.952944] 8021q: 802.1Q VLAN Support v1.8
Thu Feb  7 11:30:52 2019 kern.info kernel: [    0.988291] VFS: Mounted root (squashfs filesystem) readonly on device 31:5.
Thu Feb  7 11:30:52 2019 kern.info kernel: [    1.004305] Freeing unused kernel memory: 160K
Thu Feb  7 11:30:52 2019 kern.warn kernel: [    1.013174] This architecture does not have kernel memory protection.
Thu Feb  7 11:30:52 2019 kern.notice kernel: [    2.663429] random: fast init done
Thu Feb  7 11:30:52 2019 user.info kernel: [    4.125115] init: Console is alive
Thu Feb  7 11:30:52 2019 user.info kernel: [    4.132502] init: - watchdog -
Thu Feb  7 11:30:52 2019 user.info kernel: [    7.044974] kmodloader: loading kernel modules from /etc/modules-boot.d/*
Thu Feb  7 11:30:52 2019 user.info kernel: [    8.387281] kmodloader: done loading kernel modules from /etc/modules-boot.d/*
Thu Feb  7 11:30:52 2019 user.info kernel: [    8.412762] init: - preinit -
Thu Feb  7 11:30:52 2019 kern.info kernel: [   11.011615] rt3050-esw 10110000.esw: link changed 0x00
Thu Feb  7 11:30:52 2019 kern.info kernel: [   12.602960] rt3050-esw 10110000.esw: link changed 0x08
Thu Feb  7 11:30:52 2019 kern.info kernel: [   12.799549] rt3050-esw 10110000.esw: link changed 0x18
Thu Feb  7 11:30:52 2019 user.info kernel: [   14.648498] mount_root: loading kmods from internal overlay
Thu Feb  7 11:30:52 2019 user.info kernel: [   14.718618] kmodloader: loading kernel modules from //etc/modules-boot.d/*
Thu Feb  7 11:30:52 2019 user.info kernel: [   14.734810] kmodloader: done loading kernel modules from //etc/modules-boot.d/*
Thu Feb  7 11:30:52 2019 kern.notice kernel: [   15.741960] jffs2: notice: (332) jffs2_build_xattr_subsystem: complete building xattr subsystem, 5 of xdatum (2 unchecked, 3 orphan) and 20 of xref (3 dead, 2 orphan) found.
Thu Feb  7 11:30:52 2019 user.info kernel: [   15.774608] block: attempting to load /tmp/jffs_cfg/upper/etc/config/fstab
Thu Feb  7 11:30:52 2019 user.info kernel: [   15.803353] block: extroot: not configured
Thu Feb  7 11:30:52 2019 kern.notice kernel: [   16.162673] jffs2: notice: (330) jffs2_build_xattr_subsystem: complete building xattr subsystem, 5 of xdatum (2 unchecked, 3 orphan) and 20 of xref (3 dead, 2 orphan) found.
Thu Feb  7 11:30:52 2019 user.info kernel: [   16.850148] block: attempting to load /tmp/jffs_cfg/upper/etc/config/fstab
Thu Feb  7 11:30:52 2019 user.info kernel: [   16.875498] block: extroot: not configured
Thu Feb  7 11:30:52 2019 user.info kernel: [   16.885997] mount_root: switching to jffs2 overlay
Thu Feb  7 11:30:52 2019 kern.warn kernel: [   16.951955] overlayfs: upper fs does not support tmpfile.
Thu Feb  7 11:30:52 2019 user.warn kernel: [   16.975052] urandom-seed: Seeding with /etc/urandom.seed
Thu Feb  7 11:30:52 2019 user.info kernel: [   17.077346] procd: - early -
Thu Feb  7 11:30:52 2019 user.info kernel: [   17.083525] procd: - watchdog -
Thu Feb  7 11:30:52 2019 user.info kernel: [   18.314452] procd: - watchdog -
Thu Feb  7 11:30:52 2019 user.info kernel: [   18.321596] procd: - ubus -
Thu Feb  7 11:30:52 2019 kern.notice kernel: [   19.834436] random: ubusd: uninitialized urandom read (4 bytes read)
Thu Feb  7 11:30:52 2019 kern.notice kernel: [   19.852910] random: ubusd: uninitialized urandom read (4 bytes read)
Thu Feb  7 11:30:52 2019 kern.notice kernel: [   19.866588] random: ubusd: uninitialized urandom read (4 bytes read)
Thu Feb  7 11:30:52 2019 user.info kernel: [   19.883182] procd: - init -
Thu Feb  7 11:30:52 2019 user.info kernel: [   21.918254] kmodloader: loading kernel modules from /etc/modules.d/*
Thu Feb  7 11:30:52 2019 kern.info kernel: [   21.947304] tun: Universal TUN/TAP device driver, 1.6
Thu Feb  7 11:30:52 2019 kern.info kernel: [   21.966061] l2tp_core: L2TP core driver, V2.0
Thu Feb  7 11:30:52 2019 kern.info kernel: [   21.978426] l2tp_netlink: L2TP netlink interface
Thu Feb  7 11:30:52 2019 kern.info kernel: [   21.991573] Netfilter messages via NETLINK v0.30.
Thu Feb  7 11:30:52 2019 kern.info kernel: [   22.006060] ip_set: protocol 6
Thu Feb  7 11:30:52 2019 kern.info kernel: [   22.090676] Loading modules backported from Linux version v4.19.7-0-g61c68f2a2af0
Thu Feb  7 11:30:52 2019 kern.info kernel: [   22.105737] Backport generated by backports.git v4.19.7-1-0-g148b072d
Thu Feb  7 11:30:52 2019 kern.info kernel: [   22.126951] ip_tables: (C) 2000-2006 Netfilter Core Team
Thu Feb  7 11:30:52 2019 kern.info kernel: [   22.156349] nf_conntrack version 0.5.0 (1024 buckets, 4096 max)
Thu Feb  7 11:30:52 2019 kern.info kernel: [   22.174953] ctnetlink v0.93: registering with nfnetlink.
Thu Feb  7 11:30:52 2019 kern.info kernel: [   22.317249] xt_time: kernel timezone is -0000
Thu Feb  7 11:30:52 2019 kern.info kernel: [   22.425926] PPP generic driver version 2.4.2
Thu Feb  7 11:30:52 2019 kern.info kernel: [   22.445850] NET: Registered protocol family 24
Thu Feb  7 11:30:52 2019 kern.info kernel: [   22.477435] l2tp_ppp: PPPoL2TP kernel driver, V2.0
Thu Feb  7 11:30:52 2019 kern.info kernel: [   22.524587] rt2800_wmac 10180000.wmac: loaded eeprom from mtd device "factory"
Thu Feb  7 11:30:52 2019 kern.info kernel: [   22.539176] ieee80211 phy0: rt2x00_set_rt: Info - RT chipset 5350, rev 0500 detected
Thu Feb  7 11:30:52 2019 kern.info kernel: [   22.554714] ieee80211 phy0: rt2x00_set_rf: Info - RF chipset 5350 detected
Thu Feb  7 11:30:52 2019 kern.debug kernel: [   22.569770] ieee80211 phy0: Selected rate control algorithm 'minstrel_ht'
Thu Feb  7 11:30:52 2019 user.info kernel: [   22.621405] kmodloader: done loading kernel modules from /etc/modules.d/*
Thu Feb  7 11:30:52 2019 kern.warn kernel: [   26.763782] urandom_read: 6 callbacks suppressed
Thu Feb  7 11:30:52 2019 kern.notice kernel: [   26.763797] random: jshn: uninitialized urandom read (4 bytes read)
Thu Feb  7 11:30:56 2019 user.notice dnsmasq: DNS rebinding protection is active, will discard upstream RFC1918 responses!
Thu Feb  7 11:30:56 2019 user.notice dnsmasq: Allowing 127.0.0.0/8 responses
Thu Feb  7 11:31:00 2019 authpriv.info dropbear[740]: Not backgrounding
Thu Feb  7 11:31:01 2019 daemon.info dnsmasq[713]: started, version 2.80 cachesize 150
Thu Feb  7 11:31:01 2019 daemon.info dnsmasq[713]: DNS service limited to local subnets
Thu Feb  7 11:31:01 2019 daemon.info dnsmasq[713]: compile time options: IPv6 GNU-getopt no-DBus no-i18n no-IDN DHCP no-DHCPv6 no-Lua TFTP no-conntrack no-ipset no-auth no-DNSSEC no-ID loop-detect inotify dumpfile
Thu Feb  7 11:31:01 2019 daemon.info dnsmasq[713]: using local addresses only for domain test
Thu Feb  7 11:31:01 2019 daemon.info dnsmasq[713]: using local addresses only for domain onion
Thu Feb  7 11:31:01 2019 daemon.info dnsmasq[713]: using local addresses only for domain localhost
Thu Feb  7 11:31:01 2019 daemon.info dnsmasq[713]: using local addresses only for domain local
Thu Feb  7 11:31:01 2019 daemon.info dnsmasq[713]: using local addresses only for domain invalid
Thu Feb  7 11:31:01 2019 daemon.info dnsmasq[713]: using local addresses only for domain bind
Thu Feb  7 11:31:01 2019 daemon.info dnsmasq[713]: using local addresses only for domain lan
Thu Feb  7 11:31:01 2019 daemon.warn dnsmasq[713]: no servers found in /tmp/resolv.conf.auto, will retry
Thu Feb  7 11:31:02 2019 daemon.info dnsmasq[713]: read /etc/hosts - 4 addresses
Thu Feb  7 11:31:02 2019 daemon.info dnsmasq[713]: read /tmp/hosts/dhcp.cfg01411c - 0 addresses
Thu Feb  7 11:31:06 2019 kern.info kernel: [   42.286890] rt3050-esw 10110000.esw: link changed 0x00
Thu Feb  7 11:31:07 2019 user.notice : Added device handler type: 8021ad
Thu Feb  7 11:31:07 2019 user.notice : Added device handler type: 8021q
Thu Feb  7 11:31:07 2019 user.notice : Added device handler type: macvlan
Thu Feb  7 11:31:07 2019 user.notice : Added device handler type: veth
Thu Feb  7 11:31:07 2019 user.notice : Added device handler type: bridge
Thu Feb  7 11:31:07 2019 user.notice : Added device handler type: Network device
Thu Feb  7 11:31:07 2019 user.notice : Added device handler type: tunnel
Thu Feb  7 11:31:07 2019 daemon.notice procd: /etc/init.d/network: 'radio0' is disabled
Thu Feb  7 11:31:07 2019 daemon.notice procd: /etc/init.d/network: 'radio0' is disabled
Thu Feb  7 11:31:08 2019 kern.info kernel: [   43.882387] rt3050-esw 10110000.esw: link changed 0x08
Thu Feb  7 11:31:08 2019 kern.info kernel: [   43.898772] rt3050-esw 10110000.esw: link changed 0x18
Thu Feb  7 11:31:08 2019 daemon.err block: /dev/mtdblock5 is already mounted on /rom
Thu Feb  7 11:31:08 2019 daemon.err block: /dev/mtdblock6 is already mounted on /overlay
Thu Feb  7 11:31:09 2019 cron.info crond[845]: crond (busybox 1.30.0) started, log level 8
Thu Feb  7 11:31:13 2019 daemon.err uhttpd[875]: socket(): Address family not supported by protocol
Thu Feb  7 11:31:15 2019 daemon.info xl2tpd[902]: Not looking for kernel SAref support.
Thu Feb  7 11:31:15 2019 daemon.info xl2tpd[902]: Using l2tp kernel support.
Thu Feb  7 11:31:15 2019 daemon.info xl2tpd[902]: xl2tpd version xl2tpd-1.3.13 started on ecs PID:902
Thu Feb  7 11:31:15 2019 daemon.info xl2tpd[902]: Written by Mark Spencer, Copyright (C) 1998, Adtran, Inc.
Thu Feb  7 11:31:15 2019 daemon.info xl2tpd[902]: Forked by Scott Balmos and David Stipp, (C) 2001
Thu Feb  7 11:31:15 2019 daemon.info xl2tpd[902]: Inherited by Jeff McAdams, (C) 2002
Thu Feb  7 11:31:15 2019 daemon.info xl2tpd[902]: Forked again by Xelerance (www.xelerance.com) (C) 2006-2016
Thu Feb  7 11:31:15 2019 daemon.info xl2tpd[902]: Listening on IP address 0.0.0.0, port 1701
Thu Feb  7 11:31:17 2019 kern.info kernel: [   53.362505] device eth0 entered promiscuous mode
Thu Feb  7 11:31:17 2019 daemon.notice netifd: Interface 'lan' is enabled
Thu Feb  7 11:31:17 2019 daemon.notice netifd: Interface 'lan' is setting up now
Thu Feb  7 11:31:17 2019 kern.info kernel: [   53.375917] br-lan: port 1(eth0.1) entered blocking state
Thu Feb  7 11:31:17 2019 kern.info kernel: [   53.375943] br-lan: port 1(eth0.1) entered disabled state
Thu Feb  7 11:31:17 2019 kern.info kernel: [   53.376531] device eth0.1 entered promiscuous mode
Thu Feb  7 11:31:17 2019 kern.info kernel: [   53.379829] br-lan: port 1(eth0.1) entered blocking state
Thu Feb  7 11:31:17 2019 kern.info kernel: [   53.379857] br-lan: port 1(eth0.1) entered forwarding state
Thu Feb  7 11:31:17 2019 daemon.notice netifd: Interface 'lan' is now up
Thu Feb  7 11:31:17 2019 daemon.notice netifd: Interface 'VPN' is setting up now
Thu Feb  7 11:31:17 2019 daemon.notice netifd: Interface 'loopback' is enabled
Thu Feb  7 11:31:17 2019 daemon.notice netifd: Interface 'loopback' is setting up now
Thu Feb  7 11:31:17 2019 daemon.notice netifd: Interface 'loopback' is now up
Thu Feb  7 11:31:17 2019 daemon.notice netifd: Interface 'wan' is enabled
Thu Feb  7 11:31:17 2019 daemon.notice netifd: bridge 'br-lan' link is up
Thu Feb  7 11:31:17 2019 daemon.notice netifd: Interface 'lan' has link connectivity
Thu Feb  7 11:31:17 2019 daemon.notice netifd: Network device 'eth0' link is up
Thu Feb  7 11:31:17 2019 daemon.notice netifd: VLAN 'eth0.1' link is up
Thu Feb  7 11:31:17 2019 daemon.notice netifd: Network device 'lo' link is up
Thu Feb  7 11:31:17 2019 daemon.notice netifd: Interface 'loopback' has link connectivity
Thu Feb  7 11:31:17 2019 daemon.notice netifd: VLAN 'eth0.2' link is up
Thu Feb  7 11:31:17 2019 daemon.notice netifd: Interface 'wan' has link connectivity
Thu Feb  7 11:31:17 2019 daemon.notice netifd: Interface 'wan' is setting up now
Thu Feb  7 11:31:18 2019 authpriv.info dropbear[990]: Child connection from 192.168.1.100:54066
Thu Feb  7 11:31:20 2019 daemon.notice netifd: wan (1031): udhcpc: started, v1.30.0
Thu Feb  7 11:31:23 2019 daemon.notice netifd: wan (1031): udhcpc: sending discover
Thu Feb  7 11:31:23 2019 daemon.debug xl2tpd[902]: No such tunnel 'l2tp-VPN'
Thu Feb  7 11:31:23 2019 daemon.notice netifd: VPN (1055): xl2tpd-control: Remove l2tp-VPN failed
Thu Feb  7 11:31:23 2019 daemon.notice netifd: Interface 'VPN' is now down
Thu Feb  7 11:31:23 2019 user.notice firewall: Reloading firewall due to ifup of lan (br-lan)
Thu Feb  7 11:31:24 2019 daemon.notice netifd: wan (1031): udhcpc: sending select for 192.168.0.12
Thu Feb  7 11:31:24 2019 daemon.notice netifd: wan (1031): udhcpc: lease of 192.168.0.12 obtained, lease time 604800
Thu Feb  7 11:31:28 2019 daemon.notice netifd: Interface 'VPN' is setting up now
Thu Feb  7 11:31:28 2019 daemon.notice netifd: Interface 'wan' is now up
Thu Feb  7 11:31:28 2019 daemon.info dnsmasq[713]: reading /tmp/resolv.conf.auto
Thu Feb  7 11:31:28 2019 daemon.info dnsmasq[713]: using local addresses only for domain test
Thu Feb  7 11:31:28 2019 daemon.info dnsmasq[713]: using local addresses only for domain onion
Thu Feb  7 11:31:28 2019 daemon.info dnsmasq[713]: using local addresses only for domain localhost
Thu Feb  7 11:31:28 2019 daemon.info dnsmasq[713]: using local addresses only for domain local
Thu Feb  7 11:31:28 2019 daemon.info dnsmasq[713]: using local addresses only for domain invalid
Thu Feb  7 11:31:28 2019 daemon.info dnsmasq[713]: using local addresses only for domain bind
Thu Feb  7 11:31:28 2019 daemon.info dnsmasq[713]: using local addresses only for domain lan
Thu Feb  7 11:31:28 2019 daemon.info dnsmasq[713]: using nameserver 8.8.8.8#53
Thu Feb  7 11:31:28 2019 daemon.info dnsmasq[713]: using nameserver 8.8.4.4#53
Thu Feb  7 11:31:29 2019 daemon.notice xl2tpd[902]: Connecting to host xxx.xxx.xxx.xxx, port 1701
Thu Feb  7 11:31:29 2019 daemon.notice xl2tpd[902]: Connection established to xxx.xxx.xxx.xxx, 1701.  Local: 5877, Remote: 14026 (ref=0/0).
Thu Feb  7 11:31:29 2019 daemon.notice xl2tpd[902]: Calling on tunnel 5877
Thu Feb  7 11:31:29 2019 daemon.notice xl2tpd[902]: Call established with xxx.xxx.xxx.xxx, Local: 56738, Remote: 24621, Serial: 1 (ref=0/0)
Thu Feb  7 11:31:29 2019 daemon.debug xl2tpd[902]: start_pppd: I'm running:
Thu Feb  7 11:31:29 2019 daemon.debug xl2tpd[902]: "/usr/sbin/pppd"
Thu Feb  7 11:31:29 2019 daemon.debug xl2tpd[902]: "plugin"
Thu Feb  7 11:31:29 2019 daemon.debug xl2tpd[902]: "pppol2tp.so"
Thu Feb  7 11:31:29 2019 daemon.debug xl2tpd[902]: "pppol2tp"
Thu Feb  7 11:31:29 2019 daemon.debug xl2tpd[902]: "8"
Thu Feb  7 11:31:29 2019 daemon.debug xl2tpd[902]: "passive"
Thu Feb  7 11:31:29 2019 daemon.debug xl2tpd[902]: "nodetach"
Thu Feb  7 11:31:29 2019 daemon.debug xl2tpd[902]: ":"
Thu Feb  7 11:31:29 2019 daemon.debug xl2tpd[902]: "file"
Thu Feb  7 11:31:29 2019 daemon.debug xl2tpd[902]: "/tmp/l2tp/options.VPN"
Thu Feb  7 11:31:32 2019 daemon.info pppd[1124]: Plugin pppol2tp.so loaded.
Thu Feb  7 11:31:32 2019 daemon.notice pppd[1124]: pppd 2.4.7 started by root, uid 0
Thu Feb  7 11:31:32 2019 daemon.info pppd[1124]: Renamed interface ppp0 to l2tp-VPN
Thu Feb  7 11:31:32 2019 daemon.info pppd[1124]: Using interface l2tp-VPN
Thu Feb  7 11:31:32 2019 daemon.notice pppd[1124]: Connect: l2tp-VPN <-->
Thu Feb  7 11:31:32 2019 kern.info kernel: [   68.548224] l2tp-VPN: renamed from ppp0
Thu Feb  7 11:31:33 2019 authpriv.notice dropbear[990]: Auth succeeded with blank password for 'root' from 192.168.1.100:54066
Thu Feb  7 11:31:34 2019 daemon.info dnsmasq[713]: exiting on receipt of SIGTERM
Thu Feb  7 11:31:34 2019 daemon.notice pppd[1124]: CHAP authentication succeeded
Thu Feb  7 11:31:34 2019 user.notice root: starting ntpclient
Thu Feb  7 11:31:34 2019 daemon.info dnsmasq[1176]: started, version 2.80 cachesize 150
Thu Feb  7 11:31:34 2019 daemon.info dnsmasq[1176]: DNS service limited to local subnets
Thu Feb  7 11:31:34 2019 daemon.info dnsmasq[1176]: compile time options: IPv6 GNU-getopt no-DBus no-i18n no-IDN DHCP no-DHCPv6 no-Lua TFTP no-conntrack no-ipset no-auth no-DNSSEC no-ID loop-detect inotify dumpfile
Thu Feb  7 11:31:34 2019 daemon.info dnsmasq-dhcp[1176]: DHCP, IP range 192.168.1.100 -- 192.168.1.249, lease time 12h
Thu Feb  7 11:31:34 2019 daemon.info dnsmasq[1176]: using local addresses only for domain test
Thu Feb  7 11:31:34 2019 daemon.info dnsmasq[1176]: using local addresses only for domain onion
Thu Feb  7 11:31:34 2019 daemon.info dnsmasq[1176]: using local addresses only for domain localhost
Thu Feb  7 11:31:34 2019 daemon.info dnsmasq[1176]: using local addresses only for domain local
Thu Feb  7 11:31:34 2019 daemon.info dnsmasq[1176]: using local addresses only for domain invalid
Thu Feb  7 11:31:34 2019 daemon.info dnsmasq[1176]: using local addresses only for domain bind
Thu Feb  7 11:31:34 2019 daemon.info dnsmasq[1176]: using local addresses only for domain lan
Thu Feb  7 11:31:34 2019 daemon.info dnsmasq[1176]: reading /tmp/resolv.conf.auto
Thu Feb  7 11:31:34 2019 daemon.info dnsmasq[1176]: using local addresses only for domain test
Thu Feb  7 11:31:34 2019 daemon.info dnsmasq[1176]: using local addresses only for domain onion
Thu Feb  7 11:31:34 2019 daemon.info dnsmasq[1176]: using local addresses only for domain localhost
Thu Feb  7 11:31:34 2019 daemon.info dnsmasq[1176]: using local addresses only for domain local
Thu Feb  7 11:31:34 2019 daemon.info dnsmasq[1176]: using local addresses only for domain invalid
Thu Feb  7 11:31:34 2019 daemon.info dnsmasq[1176]: using local addresses only for domain bind
Thu Feb  7 11:31:34 2019 daemon.info dnsmasq[1176]: using local addresses only for domain lan
Thu Feb  7 11:31:34 2019 daemon.info dnsmasq[1176]: using nameserver 8.8.8.8#53
Thu Feb  7 11:31:34 2019 daemon.info dnsmasq[1176]: using nameserver 8.8.4.4#53
Thu Feb  7 11:31:34 2019 daemon.info dnsmasq[1176]: read /etc/hosts - 4 addresses
Thu Feb  7 11:31:34 2019 daemon.info dnsmasq[1176]: read /tmp/hosts/dhcp.cfg01411c - 1 addresses
Thu Feb  7 11:31:34 2019 daemon.info dnsmasq-dhcp[1176]: read /etc/ethers - 0 addresses
Thu Feb  7 11:31:34 2019 daemon.info dnsmasq[1176]: read /etc/hosts - 4 addresses
Thu Feb  7 11:31:34 2019 daemon.info dnsmasq[1176]: read /tmp/hosts/dhcp.cfg01411c - 1 addresses
Thu Feb  7 11:31:34 2019 daemon.info dnsmasq-dhcp[1176]: read /etc/ethers - 0 addresses
Thu Feb  7 11:31:34 2019 daemon.err pppd[1124]: Received bad configure-ack:
Thu Feb  7 11:31:34 2019 daemon.notice pppd[1124]: local  IP address 172.16.1.112
Thu Feb  7 11:31:34 2019 daemon.notice pppd[1124]: remote IP address 172.16.1.254
Thu Feb  7 11:31:34 2019 daemon.notice pppd[1124]: primary   DNS address 172.16.1.1
Thu Feb  7 11:31:34 2019 daemon.notice pppd[1124]: secondary DNS address 172.16.1.1
Thu Feb  7 11:31:37 2019 daemon.notice netifd: Network device 'l2tp-VPN' link is up
Thu Feb  7 11:31:37 2019 daemon.notice netifd: Interface 'VPN' is now up
Thu Feb  7 11:31:37 2019 daemon.info dnsmasq[1176]: reading /tmp/resolv.conf.auto
Thu Feb  7 11:31:37 2019 daemon.info dnsmasq[1176]: using local addresses only for domain test
Thu Feb  7 11:31:37 2019 daemon.info dnsmasq[1176]: using local addresses only for domain onion
Thu Feb  7 11:31:37 2019 daemon.info dnsmasq[1176]: using local addresses only for domain localhost
Thu Feb  7 11:31:37 2019 daemon.info dnsmasq[1176]: using local addresses only for domain local
Thu Feb  7 11:31:37 2019 daemon.info dnsmasq[1176]: using local addresses only for domain invalid
Thu Feb  7 11:31:37 2019 daemon.info dnsmasq[1176]: using local addresses only for domain bind
Thu Feb  7 11:31:37 2019 daemon.info dnsmasq[1176]: using local addresses only for domain lan
Thu Feb  7 11:31:37 2019 daemon.info dnsmasq[1176]: using nameserver 172.16.1.1#53
Thu Feb  7 11:31:37 2019 daemon.info dnsmasq[1176]: using nameserver 8.8.8.8#53
Thu Feb  7 11:31:37 2019 daemon.info dnsmasq[1176]: using nameserver 8.8.4.4#53
Thu Feb  7 11:31:37 2019 user.notice firewall: Reloading firewall due to ifup of wan (eth0.2)
Thu Feb  7 11:31:38 2019 daemon.err pppd[1124]: Received bad configure-ack:
Thu Feb  7 11:31:41 2019 daemon.err pppd[1124]: Received bad configure-ack:
Thu Feb  7 11:31:45 2019 daemon.err pppd[1124]: Received bad configure-ack:
Thu Feb  7 11:31:47 2019 user.notice ucitrack: Setting up /etc/config/network reload dependency on /etc/config/dhcp
Thu Feb  7 11:31:47 2019 user.notice ucitrack: Setting up /etc/config/network reload dependency on /etc/config/radvd
Thu Feb  7 11:31:47 2019 user.notice ucitrack: Setting up /etc/config/wireless reload dependency on /etc/config/network
Thu Feb  7 11:31:48 2019 user.notice ucitrack: Setting up /etc/config/firewall reload dependency on /etc/config/luci-splash
Thu Feb  7 11:31:48 2019 user.notice ucitrack: Setting up /etc/config/firewall reload dependency on /etc/config/qos
Thu Feb  7 11:31:48 2019 user.notice ucitrack: Setting up /etc/config/firewall reload dependency on /etc/config/miniupnpd
Thu Feb  7 11:31:48 2019 daemon.err pppd[1124]: Received bad configure-ack:
Thu Feb  7 11:31:48 2019 user.notice ucitrack: Setting up /etc/config/dhcp reload dependency on /etc/config/odhcpd
Thu Feb  7 11:31:49 2019 user.notice ucitrack: Setting up non-init /etc/config/fstab reload handler: /sbin/block mount
Thu Feb  7 11:31:49 2019 user.notice ucitrack: Setting up /etc/config/system reload trigger for non-procd /etc/init.d/led
Thu Feb  7 11:31:50 2019 user.notice ucitrack: Setting up /etc/config/system reload dependency on /etc/config/luci_statistics
Thu Feb  7 11:31:50 2019 user.notice ucitrack: Setting up /etc/config/system reload dependency on /etc/config/dhcp
Thu Feb  7 11:31:51 2019 daemon.err pppd[1124]: Received bad configure-ack:
Thu Feb  7 11:31:53 2019 daemon.info procd: - init complete -
Thu Feb  7 11:31:54 2019 daemon.err pppd[1124]: Received bad configure-ack:
Thu Feb  7 11:31:57 2019 daemon.err uhttpd[875]: luci: accepted login on /admin for root from 192.168.1.100
Thu Feb  7 11:31:58 2019 daemon.err pppd[1124]: Received bad configure-ack:
Thu Feb  7 11:32:01 2019 daemon.err pppd[1124]: Received bad configure-ack:
Thu Feb  7 11:33:10 2019 daemon.info pppd[1124]: System time change detected.
Thu Feb  7 11:33:11 2019 daemon.err pppd[1124]: Received bad configure-ack:
Thu Feb  7 11:33:14 2019 daemon.warn pppd[1124]: CCP: timeout sending Config-Requests
Thu Feb  7 11:33:33 2019 kern.notice kernel: [  123.213499] random: crng init done
Thu Feb  7 11:35:32 2019 kern.info kernel: [  242.019018] rt3050-esw 10110000.esw: link changed 0x08
Thu Feb  7 11:36:07 2019 daemon.notice xl2tpd[902]: Maximum retries exceeded for tunnel 5877.  Closing.
Thu Feb  7 11:36:07 2019 daemon.debug xl2tpd[902]: Terminating pppd: sending TERM signal to pid 1124
Thu Feb  7 11:36:07 2019 daemon.info pppd[1124]: Terminating on signal 15
Thu Feb  7 11:36:07 2019 daemon.info pppd[1124]: Connect time 3.5 minutes.
Thu Feb  7 11:36:07 2019 daemon.info pppd[1124]: Sent 2571 bytes, received 1072 bytes.
Thu Feb  7 11:36:07 2019 daemon.notice netifd: Network device 'l2tp-VPN' link is down
Thu Feb  7 11:36:07 2019 daemon.info xl2tpd[902]: Connection 14026 closed to xxx.xxx.xxx.xxx, port 1701 (Timeout)
Thu Feb  7 11:36:07 2019 daemon.notice pppd[1124]: Connection terminated.
Thu Feb  7 11:36:07 2019 daemon.info xl2tpd[902]: Disconnecting from xxx.xxx.xxx.xxx, Local: 5877, Remote: 14026
Thu Feb  7 11:36:07 2019 daemon.notice netifd: Interface 'VPN' is now down
Thu Feb  7 11:36:07 2019 daemon.notice netifd: Interface 'VPN' is setting up now
Thu Feb  7 11:36:07 2019 daemon.info dnsmasq[1176]: reading /tmp/resolv.conf.auto
Thu Feb  7 11:36:07 2019 daemon.info dnsmasq[1176]: using local addresses only for domain test
Thu Feb  7 11:36:07 2019 daemon.info dnsmasq[1176]: using local addresses only for domain onion
Thu Feb  7 11:36:07 2019 daemon.info dnsmasq[1176]: using local addresses only for domain localhost
Thu Feb  7 11:36:07 2019 daemon.info dnsmasq[1176]: using local addresses only for domain local
Thu Feb  7 11:36:07 2019 daemon.info dnsmasq[1176]: using local addresses only for domain invalid
Thu Feb  7 11:36:07 2019 daemon.info dnsmasq[1176]: using local addresses only for domain bind
Thu Feb  7 11:36:07 2019 daemon.info dnsmasq[1176]: using local addresses only for domain lan
Thu Feb  7 11:36:07 2019 daemon.info dnsmasq[1176]: using nameserver 8.8.8.8#53
Thu Feb  7 11:36:07 2019 daemon.info dnsmasq[1176]: using nameserver 8.8.4.4#53
Thu Feb  7 11:36:08 2019 user.notice root: stopping ntpclient
Thu Feb  7 11:36:08 2019 daemon.info pppd[1124]: Exit.
Thu Feb  7 11:36:08 2019 daemon.notice xl2tpd[902]: Connecting to host xxx.xxx.xxx.xxx, port 1701
Thu Feb  7 11:36:39 2019 daemon.notice xl2tpd[902]: Maximum retries exceeded for tunnel 63928.  Closing.
Thu Feb  7 11:36:39 2019 daemon.info xl2tpd[902]: Connection 0 closed to xxx.xxx.xxx.xxx, port 1701 (Timeout)
Thu Feb  7 11:37:10 2019 daemon.debug xl2tpd[902]: Unable to deliver closing message for tunnel 63928. Destroying anyway.
Thu Feb  7 11:39:07 2019 kern.info kernel: [  457.250679] rt3050-esw 10110000.esw: link changed 0x18
Thu Feb  7 11:43:36 2019 daemon.err uhttpd[875]: luci: accepted login on / for root from 192.168.1.100
Jeroenleender commented 5 years ago

above is the complete "system log" including unplugging the WAN cable and putting it back in a couple of minutes later. After leaving it plugged in for some minutes i relogged back in using Luci so it would get added to the system log so you see nothing else is being done.

yousong commented 5 years ago

@Jeroenleender

Can you please try adding option checkup_interval 10 to that VPN interface in /etc/config/network. It tells netifd to wait that many seconds to check if the interface is up since last setup attempt and retry if it's not the case. The option is documented at https://github.com/openwrt/packages/tree/master/net/xl2tpd#uci-options . It should fix the issue.

The other thing worth noting is that it seems wan down and up event did not occur along with the unplug/re-plug action (link status changed from 0x18 to 0x8, then again to 0x18). It seems that link status of switch port do not current translate to interface up/down status of switch cpu port.

Jeroenleender commented 5 years ago

@yousong Sorry for my late reply, i will check this option this weekend to see if it fixes the issue.

Is there anything we can do (workaround) for the up/down status of switch cpu port?

yousong commented 5 years ago

Is there anything we can do (workaround) for the up/down status of switch cpu port?

You can write script with swconfig command to query link status of the wan port and bring up/down eth0.2 interface. But it's just too hacky to worth going further.

I wonder maybe switchdev drivers can help in this situation, but that requires driver and userspace rewrite.

yousong commented 5 years ago

@Jeroenleender friendly remainder

yousong commented 5 years ago

Close for lack of activity. Feel free to report back if you have updates. Thank you.

iDarkEmpire commented 5 years ago

The problem, checked already on all openwrt that on stable that on snapshots: I pull out a router from a network, I connect, there is no network on L2TP I do restart through the interface in a router, a network on L2TP is I reboot L2TP connection in the router interface, the network also is

In what there can be a problem that the router does not connect L2TP after disconnection from a network?

yousong commented 5 years ago

@Jeroenleender

Can you please try adding option checkup_interval 10 to that VPN interface in /etc/config/network. It tells netifd to wait that many seconds to check if the interface is up since last setup attempt and retry if it's not the case. The option is documented at https://github.com/openwrt/packages/tree/master/net/xl2tpd#uci-options . It should fix the issue.

The other thing worth noting is that it seems wan down and up event did not occur along with the unplug/re-plug action (link status changed from 0x18 to 0x8, then again to 0x18). It seems that link status of switch port do not current translate to interface up/down status of switch cpu port.

One thing worth adding is that MAYBE after unplugging the l2tp tunnel session will detect timeout and trigger teardown and reconnect.