search

Ysurac / openmptcprouter

OpenMPTCProuter is an open source solution to aggregate multiple internet connections using Multipath TCP (MPTCP) on OpenWrt
https://www.openmptcprouter.com/
GNU General Public License v3.0
1.78k stars 258 forks source link

Internet connection stability #131

Closed fnoir closed 5 years ago

fnoir commented 6 years ago

Actual Behavior

Stability problems since 2 days

Specifications

Logs

Tue Aug 14 12:14:21 2018 kern.err kernel: [45465.205134] mptcp_detect_mapping Mappings do not match!
Tue Aug 14 12:14:21 2018 kern.err kernel: [45465.205295] mptcp_detect_mapping dseq 581697040 mdseq 581697040, sseq 1760596844 msseq 1760593988 dlen 3456 mdlen 3455 dfin 1 mdfin 1
Tue Aug 14 12:14:41 2018 kern.err kernel: [45485.382701] mptcp_detect_mapping Mappings do not match!
Tue Aug 14 12:14:41 2018 kern.err kernel: [45485.382766] mptcp_detect_mapping dseq 1835239616 mdseq 1835239616, sseq 2431739545 msseq 2431736689 dlen 3729 mdlen 3728 dfin 1 mdfin 1
Tue Aug 14 12:15:02 2018 kern.err kernel: [45506.601712] mptcp_detect_mapping Mappings do not match!
Tue Aug 14 12:15:02 2018 kern.err kernel: [45506.601835] mptcp_detect_mapping dseq 3667737336 mdseq 3667737336, sseq 887683500 msseq 887680644 dlen 11004 mdlen 11003 dfin 1 mdfin 1
Tue Aug 14 12:15:19 2018 kern.err kernel: [45522.950416] mptcp_detect_mapping Mappings do not match!
Tue Aug 14 12:15:19 2018 kern.err kernel: [45522.950481] mptcp_detect_mapping dseq 222928382 mdseq 222928382, sseq 1701788054 msseq 1701785198 dlen 5566 mdlen 5565 dfin 1 mdfin 1
Tue Aug 14 12:15:22 2018 kern.err kernel: [45526.231272] mptcp_detect_mapping Mappings do not match!
Tue Aug 14 12:15:22 2018 kern.err kernel: [45526.231338] mptcp_detect_mapping dseq 909499136 mdseq 909499136, sseq 3521021053 msseq 3521018197 dlen 3547 mdlen 3546 dfin 1 mdfin 1
Tue Aug 14 12:15:23 2018 kern.err kernel: [45527.032382] mptcp_detect_mapping Mappings do not match!
Tue Aug 14 12:15:23 2018 kern.err kernel: [45527.032463] mptcp_detect_mapping dseq 3436164763 mdseq 3436164763, sseq 2357972871 msseq 2357970015 dlen 4716 mdlen 4715 dfin 1 mdfin 1
Tue Aug 14 12:15:47 2018 kern.err kernel: [45551.064414] mptcp_detect_mapping Mappings do not match!
Tue Aug 14 12:15:47 2018 kern.err kernel: [45551.064488] mptcp_detect_mapping dseq 262533492 mdseq 262533492, sseq 2702141311 msseq 2702138455 dlen 4252 mdlen 4251 dfin 1 mdfin 1
Tue Aug 14 12:15:50 2018 kern.err kernel: [45554.070263] mptcp_detect_mapping Mappings do not match!
Tue Aug 14 12:15:50 2018 kern.err kernel: [45554.070330] mptcp_detect_mapping dseq 3670688414 mdseq 3670688414, sseq 1248294547 msseq 1248291691 dlen 4877 mdlen 4876 dfin 1 mdfin 1
Tue Aug 14 12:15:51 2018 kern.err kernel: [45555.351574] mptcp_detect_mapping Mappings do not match!
Tue Aug 14 12:15:51 2018 kern.err kernel: [45555.351636] mptcp_detect_mapping dseq 1486629519 mdseq 1486629519, sseq 726687141 msseq 726684285 dlen 4938 mdlen 4937 dfin 1 mdfin 1
Tue Aug 14 12:16:11 2018 kern.err kernel: [45575.547099] mptcp_detect_mapping Mappings do not match!
Tue Aug 14 12:16:11 2018 kern.err kernel: [45575.547190] mptcp_detect_mapping dseq 4074102701 mdseq 4074102701, sseq 1353801215 msseq 1353798359 dlen 4407 mdlen 4406 dfin 1 mdfin 1
Tue Aug 14 12:16:14 2018 kern.err kernel: [45578.172861] mptcp_detect_mapping Mappings do not match!
Tue Aug 14 12:16:14 2018 kern.err kernel: [45578.172989] mptcp_detect_mapping dseq 3183212403 mdseq 3183212403, sseq 4207847277 msseq 4207844421 dlen 4393 mdlen 4392 dfin 1 mdfin 1
Tue Aug 14 12:16:33 2018 kern.err kernel: [45597.324911] mptcp_detect_mapping Mappings do not match!
Tue Aug 14 12:16:33 2018 kern.err kernel: [45597.324974] mptcp_detect_mapping dseq 4244858597 mdseq 4244858597, sseq 2329799044 msseq 2329796188 dlen 2954 mdlen 2953 dfin 1 mdfin 1
Tue Aug 14 12:16:33 2018 kern.err kernel: [45597.408115] mptcp_detect_mapping Mappings do not match!
Tue Aug 14 12:16:33 2018 kern.err kernel: [45597.408233] mptcp_detect_mapping dseq 615537540 mdseq 615537540, sseq 1484301808 msseq 1484298952 dlen 3896 mdlen 3895 dfin 1 mdfin 1
Tue Aug 14 12:16:35 2018 kern.err kernel: [45599.224359] mptcp_detect_mapping Mappings do not match!
Tue Aug 14 12:16:35 2018 kern.err kernel: [45599.224421] mptcp_detect_mapping dseq 2078629383 mdseq 2078629383, sseq 1236479626 msseq 1236476770 dlen 3729 mdlen 3728 dfin 1 mdfin 1
Tue Aug 14 12:16:53 2018 kern.err kernel: [45617.424073] mptcp_detect_mapping Mappings do not match!
Tue Aug 14 12:16:53 2018 kern.err kernel: [45617.424149] mptcp_detect_mapping dseq 58241653 mdseq 58241653, sseq 906528998 msseq 906526142 dlen 3008 mdlen 3007 dfin 1 mdfin 1
Tue Aug 14 12:16:56 2018 kern.err kernel: [45620.287066] mptcp_detect_mapping Mappings do not match!
Tue Aug 14 12:16:56 2018 kern.err kernel: [45620.287129] mptcp_detect_mapping dseq 2456706786 mdseq 2456706786, sseq 2256422262 msseq 2256419406 dlen 4578 mdlen 4577 dfin 1 mdfin 1
Tue Aug 14 12:16:56 2018 kern.err kernel: [45620.698595] mptcp_detect_mapping Mappings do not match!
Tue Aug 14 12:16:56 2018 kern.err kernel: [45620.698723] mptcp_detect_mapping dseq 1920900339 mdseq 1920900339, sseq 675683262 msseq 675680406 dlen 4483 mdlen 4482 dfin 1 mdfin 1
Tue Aug 14 12:17:13 2018 kern.err kernel: [45637.607368] mptcp_detect_mapping Mappings do not match!
Tue Aug 14 12:17:13 2018 kern.err kernel: [45637.607434] mptcp_detect_mapping dseq 881698345 mdseq 881698345, sseq 1223739203 msseq 1223736347 dlen 4160 mdlen 4159 dfin 1 mdfin 1
Tue Aug 14 12:17:18 2018 kern.err kernel: [45641.964989] mptcp_detect_mapping Mappings do not match!
Tue Aug 14 12:17:18 2018 kern.err kernel: [45641.965120] mptcp_detect_mapping dseq 3677638066 mdseq 3677638066, sseq 284088602 msseq 284085746 dlen 5568 mdlen 5567 dfin 1 mdfin 1
Tue Aug 14 12:17:18 2018 kern.err kernel: [45642.470185] mptcp_detect_mapping Mappings do not match!
Tue Aug 14 12:17:18 2018 kern.err kernel: [45642.470249] mptcp_detect_mapping dseq 2999802736 mdseq 2999802736, sseq 3627967828 msseq 3627964972 dlen 3766 mdlen 3765 dfin 1 mdfin 1
Tue Aug 14 12:17:34 2018 kern.err kernel: [45658.598671] mptcp_detect_mapping Mappings do not match!
Tue Aug 14 12:17:34 2018 kern.err kernel: [45658.598796] mptcp_detect_mapping dseq 1202011887 mdseq 1202011887, sseq 71212171 msseq 71209315 dlen 3018 mdlen 3017 dfin 1 mdfin 1
Tue Aug 14 12:17:38 2018 kern.err kernel: [45662.860468] mptcp_detect_mapping Mappings do not match!
Tue Aug 14 12:17:38 2018 kern.err kernel: [45662.860596] mptcp_detect_mapping dseq 4256546504 mdseq 4256546504, sseq 928616034 msseq 928613178 dlen 4251 mdlen 4250 dfin 1 mdfin 1
Tue Aug 14 12:17:40 2018 kern.err kernel: [45664.924073] mptcp_detect_mapping Mappings do not match!
Tue Aug 14 12:17:40 2018 kern.err kernel: [45664.924137] mptcp_detect_mapping dseq 1204818887 mdseq 1204818887, sseq 2134446237 msseq 2134443381 dlen 5183 mdlen 5182 dfin 1 mdfin 1
Tue Aug 14 12:18:15 2018 kern.err kernel: [45699.715275] mptcp_detect_mapping Mappings do not match!
Tue Aug 14 12:18:15 2018 kern.err kernel: [45699.715381] mptcp_detect_mapping dseq 1441488084 mdseq 1441488084, sseq 3060827937 msseq 3060825081 dlen 4541 mdlen 4540 dfin 1 mdfin 1
Tue Aug 14 13:35:59 2018 user.notice post-tracking-post-tracking: wan2 switched off
Tue Aug 14 13:35:59 2018 user.notice post-tracking-post-tracking: Remove server xxx.xxx.xxx.xxx route via wan2
Tue Aug 14 13:36:12 2018 user.notice post-tracking-post-tracking: Set server xxx.xxx.xxx.xxx route via wan2 metric 4
Tue Aug 14 13:36:12 2018 user.notice post-tracking-post-tracking: Multipath wan2 switched to on
Tue Aug 14 15:54:18 2018 user.notice post-tracking-post-tracking: wan2 switched off
Tue Aug 14 15:54:18 2018 user.notice post-tracking-post-tracking: Remove server xxx.xxx.xxx.xxx route via wan2
Tue Aug 14 15:58:04 2018 user.notice post-tracking-post-tracking: Set server xxx.xxx.xxx.xxx route via wan2 metric 4
Tue Aug 14 15:58:04 2018 user.notice post-tracking-post-tracking: Multipath wan2 switched to on
Tue Aug 14 16:17:30 2018 user.notice post-tracking-post-tracking: wan2 switched off
Tue Aug 14 16:17:30 2018 user.notice post-tracking-post-tracking: Remove server xxx.xxx.xxx.xxx route via wan2
Tue Aug 14 16:20:29 2018 user.notice post-tracking-post-tracking: Set server xxx.xxx.xxx.xxx route via wan2 metric 4
Tue Aug 14 16:20:29 2018 user.notice post-tracking-post-tracking: Multipath wan2 switched to on
Tue Aug 14 16:22:49 2018 user.notice post-tracking-post-tracking: wan2 switched off
Tue Aug 14 16:22:49 2018 user.notice post-tracking-post-tracking: Remove server xxx.xxx.xxx.xxx route via wan2
Tue Aug 14 16:24:07 2018 user.notice post-tracking-post-tracking: Set server xxx.xxx.xxx.xxx route via wan2 metric 4
Tue Aug 14 16:24:07 2018 user.notice post-tracking-post-tracking: Multipath wan2 switched to on
Ysurac commented 6 years ago

OpenMPTCProuter v0.31.4 that will be out in about 2 hours (CircleCI is making images), will display more info when an interface is switched off.

Maudissure commented 6 years ago

Which brand is your modem on Wan2 ?

fnoir commented 6 years ago

Huawei B593 with latest official update

Ysurac commented 6 years ago

OpenMPTCProuter v0.31.4 is available, you should at least know why the interface is detected as down.

Maudissure commented 6 years ago

Ok there :

Tue Aug 14 17:36:57 2018 daemon.err uhttpd[2815]: luci: accepted login on / for root from 192.168.1.100 Tue Aug 14 17:37:41 2018 user.notice post-tracking-post-tracking: wan1 switched off because ping from 192.168.10.2 error (8.8.4.4,9.9.9.9,1.1.1.1,1.0.0.1,80.67.169.12,8.8.4.4,9.9.9.9,1.1.1.1,1.0.0.1,80.67.169.12,4.2.2.1,8.8.8.8,9.9.9.9,1.1.1.1,1.0.0.1,80.67.169.12,80.67.169.40) Tue Aug 14 17:37:41 2018 user.notice post-tracking-post-tracking: Remove server 51.254.127.83 route via wan1 Tue Aug 14 17:38:10 2018 daemon.info dnsmasq-dhcp[5066]: DHCPREQUEST(eth0) 192.168.1.247 30:07:4d:98:17:59 Tue Aug 14 17:38:10 2018 daemon.info dnsmasq-dhcp[5066]: DHCPACK(eth0) 192.168.1.247 30:07:4d:98:17:59 Galaxy-S8 Tue Aug 14 17:38:23 2018 user.notice post-tracking-post-tracking: Set server 51.254.127.83 route via wan1 metric 3 Tue Aug 14 17:38:23 2018 user.notice post-tracking-post-tracking: Multipath wan1 switched to on Tue Aug 14 17:40:47 2018 user.notice post-tracking-post-tracking: wan1 switched off because ping from 192.168.10.2 error (8.8.4.4,9.9.9.9,1.1.1.1,1.0.0.1,80.67.169.12,8.8.4.4,9.9.9.9,1.1.1.1,1.0.0.1,80.67.169.12,4.2.2.1,8.8.8.8,9.9.9.9,1.1.1.1,1.0.0.1,80.67.169.12,80.67.169.40,8.8.8.8,8.8.4.4,9.9.9.9,1.1.1.1,1.0.0.1,80.67.169.40,8.8.8.8,80.67.169.40,4.2.2.1,8.8.8.8,8.8.4.4,9.9.9.9) Tue Aug 14 17:40:47 2018 user.notice post-tracking-post-tracking: Remove server 51.254.127.83 route via wan1

and my parameters : param

Should i declare DNS (ex 1.1.1.1 and 1.0.0.1) in my Freebox interface ?

EDIT : Hum no, didn't work

Ysurac commented 6 years ago

No, the error "wan1 switched off because ping from 192.168.10.2 error (8.8.4.4,9.9.9.9,1.1.1.1,1.0.0.1,80.67.169.12,8.8.4.4,9.9.9.9,1.1.1.1,1.0.0.1,80.67.169.12,4.2.2.1,8.8.8.8,9.9.9.9,1.1.1.1,1.0.0.1,80.67.169.12,80.67.169.40,8.8.8.8,8.8.4.4,9.9.9.9,1.1.1.1,1.0.0.1,80.67.169.40,8.8.8.8,80.67.169.40,4.2.2.1,8.8.8.8,8.8.4.4,9.9.9.9)" mean that wan1 was switched of because it was not able to ping any of the IPs in the list from this interface. So there is a network problem somewhere. Are you sure no IP are used multiples times on the network ?

Maudissure commented 6 years ago

Meanings ? The DNS IP's ?

Wow ! Lot's of Kernel errors now :

Tue Aug 14 18:31:25 2018 kern.err kernel: [ 3494.651540] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110 Tue Aug 14 18:31:25 2018 kern.err kernel: [ 3494.662397] brcmfmac: brcmf_cfg80211_dump_station: BRCMF_C_GET_ASSOCLIST unsupported, err=-110 Tue Aug 14 18:31:29 2018 kern.err kernel: [ 3498.280296] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110 Tue Aug 14 18:31:29 2018 kern.err kernel: [ 3498.291211] brcmfmac: brcmf_cfg80211_dump_station: BRCMF_C_GET_ASSOCLIST unsupported, err=-110 Tue Aug 14 18:31:35 2018 kern.err kernel: [ 3504.276502] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110 Tue Aug 14 18:31:35 2018 kern.err kernel: [ 3504.287321] brcmfmac: brcmf_cfg80211_dump_station: BRCMF_C_GET_ASSOCLIST unsupported, err=-110 Tue Aug 14 18:31:44 2018 kern.err kernel: [ 3513.289047] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110 Tue Aug 14 18:31:44 2018 kern.err kernel: [ 3513.299946] brcmfmac: brcmf_cfg80211_dump_station: BRCMF_C_GET_ASSOCLIST unsupported, err=-110 Tue Aug 14 18:31:50 2018 kern.err kernel: [ 3519.281822] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110 Tue Aug 14 18:31:50 2018 kern.err kernel: [ 3519.292725] brcmfmac: brcmf_cfg80211_dump_station: BRCMF_C_GET_ASSOCLIST unsupported, err=-110 Tue Aug 14 18:31:56 2018 kern.err kernel: [ 3525.268782] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110 Tue Aug 14 18:31:56 2018 kern.err kernel: [ 3525.279721] brcmfmac: brcmf_cfg80211_dump_station: BRCMF_C_GET_ASSOCLIST unsupported, err=-110 Tue Aug 14 18:32:02 2018 kern.err kernel: [ 3531.271638] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110 Tue Aug 14 18:32:02 2018 kern.err kernel: [ 3531.282612] brcmfmac: brcmf_cfg80211_dump_station: BRCMF_C_GET_ASSOCLIST unsupported, err=-110 Tue Aug 14 18:32:08 2018 kern.err kernel: [ 3537.264262] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110 Tue Aug 14 18:32:08 2018 kern.err kernel: [ 3537.275211] brcmfmac: brcmf_cfg80211_dump_station: BRCMF_C_GET_ASSOCLIST unsupported, err=-110 Tue Aug 14 18:32:14 2018 kern.err kernel: [ 3543.289758] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110 Tue Aug 14 18:32:14 2018 kern.err kernel: [ 3543.300674] brcmfmac: brcmf_cfg80211_dump_station: BRCMF_C_GET_ASSOCLIST unsupported, err=-110 Tue Aug 14 18:32:20 2018 kern.err kernel: [ 3549.278177] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110 Tue Aug 14 18:32:20 2018 kern.err kernel: [ 3549.289103] brcmfmac: brcmf_cfg80211_dump_station: BRCMF_C_GET_ASSOCLIST unsupported, err=-110 Tue Aug 14 18:32:26 2018 kern.err kernel: [ 3555.276365] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110 Tue Aug 14 18:32:26 2018 kern.err kernel: [ 3555.287249] brcmfmac: brcmf_cfg80211_dump_station: BRCMF_C_GET_ASSOCLIST unsupported, err=-110 Tue Aug 14 18:32:32 2018 kern.err kernel: [ 3561.279582] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110 Tue Aug 14 18:32:32 2018 kern.err kernel: [ 3561.290422] brcmfmac: brcmf_cfg80211_dump_station: BRCMF_C_GET_ASSOCLIST unsupported, err=-110 Tue Aug 14 18:32:38 2018 kern.err kernel: [ 3567.265440] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110 Tue Aug 14 18:32:38 2018 kern.err kernel: [ 3567.276343] brcmfmac: brcmf_cfg80211_dump_station: BRCMF_C_GET_ASSOCLIST unsupported, err=-110 Tue Aug 14 18:32:44 2018 kern.err kernel: [ 3573.273077] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110 Tue Aug 14 18:32:44 2018 kern.err kernel: [ 3573.284228] brcmfmac: brcmf_cfg80211_dump_station: BRCMF_C_GET_ASSOCLIST unsupported, err=-110 Tue Aug 14 18:32:50 2018 kern.err kernel: [ 3579.282131] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110 Tue Aug 14 18:32:50 2018 kern.err kernel: [ 3579.293040] brcmfmac: brcmf_cfg80211_dump_station: BRCMF_C_GET_ASSOCLIST unsupported, err=-110 Tue Aug 14 18:32:56 2018 kern.err kernel: [ 3585.276392] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110 Tue Aug 14 18:32:56 2018 kern.err kernel: [ 3585.290158] brcmfmac: brcmf_cfg80211_dump_station: BRCMF_C_GET_ASSOCLIST unsupported, err=-110 Tue Aug 14 18:33:02 2018 kern.err kernel: [ 3591.288542] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110 Tue Aug 14 18:33:02 2018 kern.err kernel: [ 3591.299486] brcmfmac: brcmf_cfg80211_dump_station: BRCMF_C_GET_ASSOCLIST unsupported, err=-110 Tue Aug 14 18:33:08 2018 kern.err kernel: [ 3597.266522] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110 Tue Aug 14 18:33:08 2018 kern.err kernel: [ 3597.277427] brcmfmac: brcmf_cfg80211_dump_station: BRCMF_C_GET_ASSOCLIST unsupported, err=-110 Tue Aug 14 18:33:09 2018 user.notice post-tracking-post-tracking: wan1 switched off because ping from 192.168.10.2 error (8.8.4.4,9.9.9.9,1.1.1.1,1.0.0.1,80.67.169.12,8.8.4.4,9.9.9.9,1.1.1.1,1.0.0.1,80.67.169.12,4.2.2.1,8.8.8.8,9.9.9.9,1.1.1.1,1.0.0.1,80.67.169.12,80.67.169.40,8.8.8.8,8.8.4.4,9.9.9.9,1.1.1.1,1.0.0.1,80.67.169.40,8.8.8.8,80.67.169.40,4.2.2.1,8.8.8.8,8.8.4.4,9.9.9.9,1.0.0.1,80.67.169.12,80.67.169.40,4.2.2.1,8.8.8.8,80.67.169.12,80.67.169.40,4.2.2.1,8.8.8.8,8.8.4.4,1.1.1.1,1.0.0.1,80.67.169.12,80.67.169.40,4.2.2.1,1.0.0.1,80.67.169.12,80.67.169.40,4.2.2.1,1.0.0.1,80.67.169.12,80.67.169.40,4.2.2.1,8.8.8.8,9.9.9.9,1.1.1.1,1.0.0.1,80.67.169.12,80.67.169.40,8.8.8.8,8.8.4.4,9.9.9.9,1.1.1.1,1.0.0.1,80.67.169.40,4.2.2.1,8.8.8.8,1.0.0.1,80.67.169.12,80.67.169.40,4.2.2.1,8.8.8.8,9.9.9.9,1.1.1.1,1.0.0.1,80.67.169.12,80.67.169.40,8.8.8.8,8.8.4.4,9.9.9.9,80.67.169.40,4.2.2.1,8.8.8.8,8.8.4.4,9.9.9.9,80.67.169.12,80.67.169.40,4.2.2.1,8.8.8.8,8.8.4.4,1.1.1.1,8.8.8.8,9.9.9.9,1.1.1.1,1.0.0.1,80.67.169.12,80.67.169.40,8.8.8.8,8. Tue Aug 14 18:33:09 2018 user.notice post-tracking-post-tracking: Remove server 51.254.127.83 route via wan1 Tue Aug 14 18:33:14 2018 kern.err kernel: [ 3603.287819] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110 Tue Aug 14 18:33:14 2018 kern.err kernel: [ 3603.298646] brcmfmac: brcmf_cfg80211_dump_station: BRCMF_C_GET_ASSOCLIST unsupported, err=-110 Tue Aug 14 18:33:20 2018 kern.err kernel: [ 3609.280909] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110 Tue Aug 14 18:33:20 2018 kern.err kernel: [ 3609.291782] brcmfmac: brcmf_cfg80211_dump_station: BRCMF_C_GET_ASSOCLIST unsupported, err=-110 Tue Aug 14 18:33:26 2018 kern.err kernel: [ 3615.287017] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110 Tue Aug 14 18:33:26 2018 kern.err kernel: [ 3615.297895] brcmfmac: brcmf_cfg80211_dump_station: BRCMF_C_GET_ASSOCLIST unsupported, err=-110 Tue Aug 14 18:33:32 2018 kern.err kernel: [ 3621.289086] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110 Tue Aug 14 18:33:32 2018 kern.err kernel: [ 3621.300013] brcmfmac: brcmf_cfg80211_dump_station: BRCMF_C_GET_ASSOCLIST unsupported, err=-110 Tue Aug 14 18:33:38 2018 kern.err kernel: [ 3627.268156] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110 Tue Aug 14 18:33:38 2018 kern.err kernel: [ 3627.279079] brcmfmac: brcmf_cfg80211_dump_station: BRCMF_C_GET_ASSOCLIST unsupported, err=-110 Tue Aug 14 18:33:40 2018 kern.err kernel: [ 3629.942406] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110 Tue Aug 14 18:33:40 2018 kern.err kernel: [ 3629.953321] brcmfmac: brcmf_cfg80211_dump_station: BRCMF_C_GET_ASSOCLIST unsupported, err=-110 Tue Aug 14 18:33:43 2018 kern.err kernel: [ 3632.651670] brcmfmac: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110 Tue Aug 14 18:33:43 2018 kern.err kernel: [ 3632.662540] brcmfmac: brcmf_cfg80211_dump_station: BRCMF_C_GET_ASSOCLIST unsupported, err=-110 Tue Aug 14 18:33:50 2018 user.notice post-tracking-post-tracking: Set server 51.254.127.83 route via wan1 metric 3 Tue Aug 14 18:33:50 2018 user.notice post-tracking-post-tracking: Multipath wan1 switched to on

Ysurac commented 6 years ago

It's DNS servers, but they are, by default, only used for ping test. If they answer to ping than interface is up, else down.

The errors are about wifi brcmfmac module. I will check if there is a fix/workaround for that...

Maudissure commented 6 years ago

And where to search for the DNS ping issue ?

Ysurac commented 6 years ago

I make a mistake, this will be fixed in OpenMPTCProuter v0.31.5, CircleCI compile image, this will be available in a few hours.

fnoir commented 6 years ago

Now, i have:

image

Wed Aug 15 09:21:42 2018 user.notice post-tracking-post-tracking: omrvpn down
Wed Aug 15 09:21:42 2018 user.notice post-tracking-post-tracking: omrvpn down. Replace default route by 192.168.5.1 dev wan1
Wed Aug 15 09:21:42 2018 daemon.info unbound: [6837:0] info: service stopped (unbound 1.7.3).
Wed Aug 15 09:21:42 2018 daemon.info unbound: [6837:0] info: server stats for thread 0: 8 queries, 0 answers from cache, 8 recursions, 0 prefetch, 0 rejected by ip ratelimiting
Wed Aug 15 09:21:42 2018 daemon.info unbound: [6837:0] info: server stats for thread 0: requestlist max 7 avg 2.75 exceeded 0 jostled 0
Wed Aug 15 09:21:42 2018 daemon.info unbound: [6837:0] info: average recursion processing time 0.197948 sec
Wed Aug 15 09:21:42 2018 daemon.info unbound: [6837:0] info: histogram of recursion processing times
Wed Aug 15 09:21:42 2018 daemon.info unbound: [6837:0] info: [25%]=0.098304 median[50%]=0.196608 [75%]=0.349525
Wed Aug 15 09:21:42 2018 daemon.info unbound: [6837:0] info: lower(secs) upper(secs) recursions
Wed Aug 15 09:21:42 2018 daemon.info unbound: [6837:0] info:    0.016384    0.032768 1
Wed Aug 15 09:21:42 2018 daemon.info unbound: [6837:0] info:    0.065536    0.131072 2
Wed Aug 15 09:21:42 2018 daemon.info unbound: [6837:0] info:    0.131072    0.262144 2
Wed Aug 15 09:21:42 2018 daemon.info unbound: [6837:0] info:    0.262144    0.524288 3
Wed Aug 15 09:21:42 2018 daemon.notice unbound: [7127:0] notice: init module 0: validator
Wed Aug 15 09:21:42 2018 daemon.notice unbound: [7127:0] notice: init module 1: iterator
Wed Aug 15 09:21:42 2018 daemon.info unbound: [7127:0] info: start of service (unbound 1.7.3).
Wed Aug 15 09:21:50 2018 daemon.info unbound: [7127:0] info: generate keytag query _ta-4a5c-4f66. NULL IN
Wed Aug 15 09:21:53 2018 user.notice post-tracking-post-tracking: Tunnel up : Replace default route by 10.255.255.1 dev tun0
Wed Aug 15 09:21:56 2018 user.notice post-tracking-post-tracking: Set server xxx.xxx.xxx.xxx route via wan1 metric 1
Wed Aug 15 09:24:00 2018 daemon.err /usr/bin/ss-redir[6287]: remote recv: Operation timed out
Wed Aug 15 09:24:00 2018 daemon.err /usr/bin/ss-redir[6287]: remote recv: Operation timed out

I can't play video games for exemple because i have a latency that varies from 40ms to 2500ms.

OpenMPTCProuter version: v0.31.6 r7254-75e4d2d18c

Ysurac commented 6 years ago

Status page is ok. ss-redir operation timed out are normal. You seems to have a problem with the tunnel. It's used for ICMP and UDP. I will check tomorrow how I can test it and fix when there is problems.

fnoir commented 6 years ago

I think i achieved the limit of consumption with LTE card (1.6TB)... :D It isn't unlimited...

Ysurac commented 6 years ago

You're not using Free mobile 4G with a Freebox ? It's what I have and it's really unlimited.

fnoir commented 6 years ago

I use Free mobile LTE with a Freebox but, today, LTE is limited (100kb/s). I reboot my router and i have same result on my phone or router

Ysurac commented 6 years ago

Maybe many users, I had the same problem in July.

Maudissure commented 6 years ago

After some hours, network seems stable. Internet connection too. No routrer's crash also.

You're on the good way, keep going ! And thanks for all works you do.

Maudissure commented 6 years ago

talked too fast, i got instable internet connections.

Many cuts in radio streaming (on logitech squeezebox), my professional laptop (a lenovo thinkpad from 2014) hardly get an internet connection, however other devices except Apple devices seems working.

And after a soft reboot, router became unavalaible (despite system was on). Needed an hard reboot to recover network access to the router.

fnoir commented 6 years ago

With openmptcprouter v0.31.7, same problems : 

Sat Aug 18 16:07:02 2018 daemon.err glorytun[5367]: read: Operation timed out
Sat Aug 18 16:07:02 2018 daemon.info glorytun[5367]: STOPPED tun0
Sat Aug 18 16:07:10 2018 daemon.err glorytun[5367]: xxx.xxx.xxx.xxx.65001: connected
Sat Aug 18 16:07:10 2018 daemon.info glorytun[5367]: STARTED tun0
Sat Aug 18 16:08:07 2018 daemon.err /usr/bin/ss-redir[6359]: remote recv: Operation timed out
Sat Aug 18 16:08:07 2018 daemon.err /usr/bin/ss-redir[6359]: remote recv: Operation timed out
Sat Aug 18 16:08:07 2018 daemon.err /usr/bin/ss-redir[6359]: remote recv: Operation timed out
Sat Aug 18 16:08:07 2018 daemon.err /usr/bin/ss-redir[6359]: remote recv: Operation timed out
Sat Aug 18 16:08:21 2018 daemon.err glorytun[5367]: read: Operation timed out
Sat Aug 18 16:08:21 2018 daemon.info glorytun[5367]: STOPPED tun0
Sat Aug 18 16:08:38 2018 daemon.err /usr/bin/ss-redir[6359]: remote recv: Operation timed out
Sat Aug 18 16:08:38 2018 daemon.err /usr/bin/ss-redir[6359]: remote recv: Operation timed out
Sat Aug 18 16:08:38 2018 daemon.err /usr/bin/ss-redir[6359]: remote recv: Operation timed out
Sat Aug 18 16:08:38 2018 daemon.err /usr/bin/ss-redir[6359]: remote recv: Operation timed out
Sat Aug 18 16:08:38 2018 daemon.err glorytun[5367]: xxx.xxx.xxx.xxx.65001: connected
Sat Aug 18 16:08:43 2018 daemon.err /usr/bin/ss-redir[6359]: remote recv: Operation timed out
Sat Aug 18 16:08:43 2018 daemon.err /usr/bin/ss-redir[6359]: remote recv: Operation timed out
Sat Aug 18 16:08:48 2018 daemon.err /usr/bin/ss-redir[6359]: remote recv: Operation timed out
Sat Aug 18 16:08:48 2018 daemon.err /usr/bin/ss-redir[6359]: remote recv: Operation timed out
Sat Aug 18 16:08:48 2018 daemon.err /usr/bin/ss-redir[6359]: remote recv: Operation timed out
Sat Aug 18 16:08:48 2018 daemon.err /usr/bin/ss-redir[6359]: remote recv: Operation timed out
Sat Aug 18 16:09:18 2018 daemon.err glorytun[5367]: xxx.xxx.xxx.xxx.65001: key exchange failed
Sat Aug 18 16:09:18 2018 daemon.info glorytun[5367]: STOPPED tun0
Sat Aug 18 16:09:19 2018 daemon.err glorytun[5367]: xxx.xxx.xxx.xxx.65001: connected
Sat Aug 18 16:09:59 2018 daemon.err glorytun[5367]: xxx.xxx.xxx.xxx.65001: key exchange failed
Sat Aug 18 16:09:59 2018 daemon.info glorytun[5367]: STOPPED tun0
Sat Aug 18 16:10:00 2018 daemon.err glorytun[5367]: xxx.xxx.xxx.xxx.65001: connected
Sat Aug 18 16:10:27 2018 daemon.notice netifd: omrvpn (5439): udhcpc: sending renew to 10.255.255.1
Sat Aug 18 16:10:40 2018 daemon.err glorytun[5367]: xxx.xxx.xxx.xxx.65001: key exchange failed
Sat Aug 18 16:10:40 2018 daemon.info glorytun[5367]: STOPPED tun0
Sat Aug 18 16:10:41 2018 daemon.err glorytun[5367]: xxx.xxx.xxx.xxx.65001: connected
Sat Aug 18 16:11:19 2018 daemon.info glorytun[5367]: STARTED tun0
Sat Aug 18 16:27:12 2018 daemon.err glorytun[5367]: read: Operation timed out
Sat Aug 18 16:27:12 2018 daemon.info glorytun[5367]: STOPPED tun0
Sat Aug 18 16:27:13 2018 daemon.err glorytun[5367]: xxx.xxx.xxx.xxx.65001: connected
Sat Aug 18 16:27:44 2018 daemon.err /usr/bin/ss-redir[6359]: remote recv: Connection reset by peer
Sat Aug 18 16:27:53 2018 daemon.err glorytun[5367]: xxx.xxx.xxx.xxx.65001: key exchange failed
Sat Aug 18 16:27:53 2018 daemon.info glorytun[5367]: STOPPED tun0
Sat Aug 18 16:27:54 2018 daemon.err glorytun[5367]: xxx.xxx.xxx.xxx.65001: connected
Sat Aug 18 16:28:34 2018 daemon.err glorytun[5367]: xxx.xxx.xxx.xxx.65001: key exchange failed
Sat Aug 18 16:28:34 2018 daemon.info glorytun[5367]: STOPPED tun0
Sat Aug 18 16:28:35 2018 daemon.err glorytun[5367]: xxx.xxx.xxx.xxx.65001: connected
Sat Aug 18 16:28:46 2018 daemon.err /usr/bin/ss-local[6357]: getpeername: Socket not connected
Sat Aug 18 16:28:51 2018 daemon.err /usr/bin/ss-redir[6359]: remote recv: Operation timed out
Sat Aug 18 16:29:15 2018 daemon.err glorytun[5367]: xxx.xxx.xxx.xxx.65001: key exchange failed
Sat Aug 18 16:29:15 2018 daemon.info glorytun[5367]: STOPPED tun0
Sat Aug 18 16:29:16 2018 daemon.err glorytun[5367]: xxx.xxx.xxx.xxx.65001: connected
Sat Aug 18 16:29:56 2018 daemon.err glorytun[5367]: xxx.xxx.xxx.xxx.65001: key exchange failed
Sat Aug 18 16:29:56 2018 daemon.info glorytun[5367]: STOPPED tun0
Sat Aug 18 16:29:57 2018 daemon.err glorytun[5367]: xxx.xxx.xxx.xxx.65001: connected
Sat Aug 18 16:30:37 2018 daemon.err glorytun[5367]: xxx.xxx.xxx.xxx.65001: key exchange failed
Sat Aug 18 16:30:37 2018 daemon.info glorytun[5367]: STOPPED tun0
Sat Aug 18 16:30:38 2018 daemon.err glorytun[5367]: xxx.xxx.xxx.xxx.65001: connected
Sat Aug 18 16:31:18 2018 daemon.err glorytun[5367]: xxx.xxx.xxx.xxx.65001: key exchange failed
Sat Aug 18 16:31:18 2018 daemon.info glorytun[5367]: STOPPED tun0
Sat Aug 18 16:31:35 2018 daemon.err glorytun[5367]: xxx.xxx.xxx.xxx.65001: connected
Sat Aug 18 16:32:02 2018 daemon.info glorytun[5367]: STARTED tun0
Ysurac commented 6 years ago

The problem seems to be a very bad connection between master wan and server. What is the result of ip route on OpenMPTCProuter ? You can also try to restart glorytun TCP on the server, I had some problem with it...

fnoir commented 6 years ago

I restart server & router and same problems.

Sorry, i need stable connection this week, i turn off OpenMPTCP for moment.

Maudissure commented 6 years ago

i'm getting this message regulary, is this important ? (OMR V0.32):

Sat Aug 18 17:05:23 2018 daemon.warn odhcpd[1529]: A default route is present but there is no public prefix on eth0 thus we don't announce a default route!

Ysurac commented 6 years ago

Not really, it's because in Interface->lan->DHCP->IPv6 Always announce default router is not enabled. Should be by default but something seems to remove it... Will be fixed in next release.

Ysurac commented 6 years ago

It's not kernel issues. It's an "error" in the wifi driver. I will add a patch that remove this warning.

Maudissure commented 6 years ago

OMR V0.32.1

Sorry just see that i had the same issue before with answer from you. You're too fast to answer :D .

However no crash after 12 hours on. I think i may have some DNS issues because internet access take a while to work this morning (about 3 min to reconnect). I dunno for what reason ...

This message could it be related to this issue ? Sun Aug 19 07:24:56 2018 daemon.err uhttpd[4402]: Host whois.ripe.net not found.

Also no more radio streaming issues, it works now.

For me it's only remaining Apple devices connection issues but with some changes :

iPhone 6S : Cannot get IPV4 from DHCP but connection ok with manual IP parameters with OMR subnet and DNS set manualy to OMR IP.

iPad Air 2 and Apple TV 4K : Cannot get IPV4 from DHCP nor internet connection with manual IP parameters with OMR subnet and DNS set manualy to OMR IP.

nileio commented 6 years ago

please try restarting dnsmasq /etc/init.d/dnsmasq restart

now the warning message "A default route is present but there is no public prefix on eth0 thus we don't announce a default route!" is a possible bug https://github.com/openwrt/odhcpd/issues/79 it has to do with ipv6 but yet to find out more

Maudissure commented 6 years ago

V0.32.3

After few hours on, internet connection very slow.

Soft reboot : No more internal or internet network connections (System reboot correctly, DHCP functional). Hard reboot : Retrieve all connections.

restarted dnsmasq, not better :

Tue Aug 21 18:49:10 2018 daemon.info dnsmasq-dhcp[19182]: DHCPOFFER(eth0) 192.168.1.208 b4:8b:19:1b:4e:ee Tue Aug 21 18:49:11 2018 daemon.info dnsmasq-dhcp[19182]: DHCPREQUEST(eth0) 192.168.1.208 b4:8b:19:1b:4e:ee Tue Aug 21 18:49:11 2018 daemon.info dnsmasq-dhcp[19182]: DHCPACK(eth0) 192.168.1.208 b4:8b:19:1b:4e:ee iPhone Tue Aug 21 18:49:14 2018 daemon.warn dnsmasq-dhcp[19182]: not using configured address 192.168.1.54 because it was previously declined Tue Aug 21 18:49:16 2018 daemon.err /usr/bin/ss-redir[7167]: remote recv: Connection reset by peer Tue Aug 21 18:49:18 2018 daemon.info dnsmasq-dhcp[19182]: DHCPDISCOVER(eth0) d0:d2:b0:83:83:16 Tue Aug 21 18:49:18 2018 daemon.info dnsmasq-dhcp[19182]: DHCPOFFER(eth0) 192.168.1.212 d0:d2:b0:83:83:16 Tue Aug 21 18:49:18 2018 daemon.warn dnsmasq-dhcp[19182]: not using configured address 192.168.1.54 because it was previously declined Tue Aug 21 18:49:18 2018 daemon.info dnsmasq-dhcp[19182]: DHCPDISCOVER(eth0) d0:d2:b0:83:83:16 Tue Aug 21 18:49:18 2018 daemon.info dnsmasq-dhcp[19182]: DHCPOFFER(eth0) 192.168.1.212 d0:d2:b0:83:83:16 Tue Aug 21 18:49:18 2018 daemon.info dnsmasq-dhcp[19182]: DHCPDECLINE(eth0) 192.168.1.208 b4:8b:19:1b:4e:ee Tue Aug 21 18:49:19 2018 daemon.info dnsmasq-dhcp[19182]: DHCPREQUEST(eth0) 192.168.1.212 d0:d2:b0:83:83:16 Tue Aug 21 18:49:19 2018 daemon.info dnsmasq-dhcp[19182]: DHCPACK(eth0) 192.168.1.212 d0:d2:b0:83:83:16 Apple_TV Tue Aug 21 18:49:19 2018 daemon.warn dnsmasq-dhcp[19182]: not giving name Apple_TV.lan to the DHCP lease of 192.168.1.212 because the name exists in /tmp/hosts/dhcp.cfg01411c with address 192.168.1.54 Tue Aug 21 18:49:24 2018 daemon.info dnsmasq-dhcp[19182]: DHCPDECLINE(eth0) 192.168.1.212 d0:d2:b0:83:83:16 Tue Aug 21 18:49:30 2018 daemon.info dnsmasq-dhcp[19182]: DHCPDISCOVER(eth0) b4:8b:19:1b:4e:ee Tue Aug 21 18:49:30 2018 daemon.info dnsmasq-dhcp[19182]: DHCPOFFER(eth0) 192.168.1.210 b4:8b:19:1b:4e:ee Tue Aug 21 18:49:30 2018 daemon.info dnsmasq-dhcp[19182]: DHCPDISCOVER(eth0) b4:8b:19:1b:4e:ee Tue Aug 21 18:49:30 2018 daemon.info dnsmasq-dhcp[19182]: DHCPOFFER(eth0) 192.168.1.210 b4:8b:19:1b:4e:ee Tue Aug 21 18:49:31 2018 daemon.info dnsmasq-dhcp[19182]: DHCPREQUEST(eth0) 192.168.1.210 b4:8b:19:1b:4e:ee Tue Aug 21 18:49:31 2018 daemon.info dnsmasq-dhcp[19182]: DHCPACK(eth0) 192.168.1.210 b4:8b:19:1b:4e:ee iPhone

fnoir commented 5 years ago

New problem with openmptcprouter v0.37 r7320-8a006c2480 : 

Tue Sep 25 17:17:55 2018 daemon.err glorytun[22301]: read: Operation timed out
Tue Sep 25 17:17:55 2018 daemon.info glorytun[22301]: STOPPED tun0
Tue Sep 25 17:18:00 2018 daemon.err glorytun[22301]: xxx.xxx.xxx.xxx.65001: connected
Tue Sep 25 17:18:04 2018 daemon.err glorytun[22301]: xxx.xxx.xxx.xxx.65001: key exchange failed
Tue Sep 25 17:18:04 2018 daemon.info glorytun[22301]: STOPPED tun0
Tue Sep 25 17:18:12 2018 daemon.err glorytun[22301]: xxx.xxx.xxx.xxx.65001: connected
Tue Sep 25 17:18:16 2018 daemon.err glorytun[22301]: xxx.xxx.xxx.xxx.65001: key exchange failed
Tue Sep 25 17:18:16 2018 daemon.info glorytun[22301]: STOPPED tun0
Tue Sep 25 17:18:20 2018 daemon.err glorytun[22301]: xxx.xxx.xxx.xxx.65001: connected
Tue Sep 25 17:18:24 2018 daemon.err glorytun[22301]: xxx.xxx.xxx.xxx.65001: key exchange failed
Tue Sep 25 17:18:24 2018 daemon.info glorytun[22301]: STOPPED tun0
Tue Sep 25 17:18:24 2018 daemon.err glorytun[22301]: xxx.xxx.xxx.xxx.65001: connected
Tue Sep 25 17:18:28 2018 daemon.err glorytun[22301]: xxx.xxx.xxx.xxx.65001: key exchange failed
Tue Sep 25 17:18:28 2018 daemon.info glorytun[22301]: STOPPED tun0
Tue Sep 25 17:18:28 2018 daemon.err glorytun[22301]: xxx.xxx.xxx.xxx.65001: connected
Tue Sep 25 17:18:32 2018 daemon.err glorytun[22301]: xxx.xxx.xxx.xxx.65001: key exchange failed
Tue Sep 25 17:18:32 2018 daemon.info glorytun[22301]: STOPPED tun0
Tue Sep 25 17:18:32 2018 daemon.err glorytun[22301]: xxx.xxx.xxx.xxx.65001: connected
Tue Sep 25 17:18:36 2018 daemon.err glorytun[22301]: xxx.xxx.xxx.xxx.65001: key exchange failed
Tue Sep 25 17:18:36 2018 daemon.info glorytun[22301]: STOPPED tun0
Tue Sep 25 17:18:36 2018 daemon.err glorytun[22301]: xxx.xxx.xxx.xxx.65001: connected
Tue Sep 25 17:18:40 2018 daemon.err glorytun[22301]: xxx.xxx.xxx.xxx.65001: key exchange failed
Tue Sep 25 17:18:40 2018 daemon.info glorytun[22301]: STOPPED tun0
Tue Sep 25 17:18:40 2018 daemon.err glorytun[22301]: xxx.xxx.xxx.xxx.65001: connected
Tue Sep 25 17:18:44 2018 daemon.err glorytun[22301]: xxx.xxx.xxx.xxx.65001: key exchange failed
Tue Sep 25 17:18:44 2018 daemon.info glorytun[22301]: STOPPED tun0
Tue Sep 25 17:18:44 2018 daemon.err glorytun[22301]: xxx.xxx.xxx.xxx.65001: connected
Tue Sep 25 17:18:48 2018 daemon.err glorytun[22301]: xxx.xxx.xxx.xxx.65001: key exchange failed
Tue Sep 25 17:18:48 2018 daemon.info glorytun[22301]: STOPPED tun0
Tue Sep 25 17:18:52 2018 daemon.err glorytun[22301]: xxx.xxx.xxx.xxx.65001: connected
Tue Sep 25 17:18:53 2018 daemon.info glorytun[22301]: STARTED tun0
Ysurac commented 5 years ago

You can try to restart glorytun-tcp on the VPS (or restart the VPS) and also check the key. If no change check your connections (high ping between OMR and the VPS or lot of packets lost).

fnoir commented 5 years ago

I have 2 adsl connections now (very stable, ping <20ms).

Every 2 hours:

Thu Sep 27 09:48:20 2018 daemon.err glorytun[5092]: read: Operation timed out
Thu Sep 27 09:48:20 2018 daemon.info glorytun[5092]: STOPPED tun0
Thu Sep 27 09:48:20 2018 daemon.err glorytun[5092]: xxx.xxx.xxx.xxx.65001: connected
Thu Sep 27 09:48:24 2018 daemon.err glorytun[5092]: xxx.xxx.xxx.xxx.65001: key exchange failed
Thu Sep 27 09:48:24 2018 daemon.info glorytun[5092]: STOPPED tun0
Thu Sep 27 09:48:24 2018 daemon.err glorytun[5092]: xxx.xxx.xxx.xxx.65001: connected
Thu Sep 27 09:48:28 2018 daemon.err glorytun[5092]: xxx.xxx.xxx.xxx.65001: key exchange failed
Thu Sep 27 09:48:28 2018 daemon.info glorytun[5092]: STOPPED tun0
Thu Sep 27 09:48:36 2018 daemon.err glorytun[5092]: xxx.xxx.xxx.xxx.65001: connected
Thu Sep 27 09:48:40 2018 daemon.err glorytun[5092]: xxx.xxx.xxx.xxx.65001: key exchange failed
Thu Sep 27 09:48:40 2018 daemon.info glorytun[5092]: STOPPED tun0
Thu Sep 27 09:48:45 2018 daemon.err glorytun[5092]: xxx.xxx.xxx.xxx.65001: connected
Thu Sep 27 09:48:49 2018 daemon.err glorytun[5092]: xxx.xxx.xxx.xxx.65001: key exchange failed
Thu Sep 27 09:48:49 2018 daemon.info glorytun[5092]: STOPPED tun0
Thu Sep 27 09:48:53 2018 daemon.err glorytun[5092]: xxx.xxx.xxx.xxx.65001: connected
Thu Sep 27 09:48:57 2018 daemon.err glorytun[5092]: xxx.xxx.xxx.xxx.65001: key exchange failed
Thu Sep 27 09:48:57 2018 daemon.info glorytun[5092]: STOPPED tun0
Thu Sep 27 09:48:57 2018 daemon.err glorytun[5092]: xxx.xxx.xxx.xxx.65001: connected
Thu Sep 27 09:49:01 2018 daemon.err glorytun[5092]: xxx.xxx.xxx.xxx.65001: key exchange failed
Thu Sep 27 09:49:01 2018 daemon.info glorytun[5092]: STOPPED tun0
Thu Sep 27 09:49:01 2018 daemon.err glorytun[5092]: xxx.xxx.xxx.xxx.65001: connected
Thu Sep 27 09:49:05 2018 daemon.err glorytun[5092]: xxx.xxx.xxx.xxx.65001: key exchange failed
Thu Sep 27 09:49:05 2018 daemon.info glorytun[5092]: STOPPED tun0
Thu Sep 27 09:49:05 2018 daemon.err glorytun[5092]: xxx.xxx.xxx.xxx.65001: connected
Thu Sep 27 09:49:09 2018 daemon.err glorytun[5092]: xxx.xxx.xxx.xxx.65001: key exchange failed
Thu Sep 27 09:49:09 2018 daemon.info glorytun[5092]: STOPPED tun0
Thu Sep 27 09:49:09 2018 daemon.err glorytun[5092]: xxx.xxx.xxx.xxx.65001: connected
Thu Sep 27 09:49:13 2018 daemon.err glorytun[5092]: xxx.xxx.xxx.xxx.65001: key exchange failed
Thu Sep 27 09:49:13 2018 daemon.info glorytun[5092]: STOPPED tun0
Thu Sep 27 09:49:14 2018 daemon.err glorytun[5092]: xxx.xxx.xxx.xxx.65001: connected
Thu Sep 27 09:49:15 2018 daemon.info glorytun[5092]: STARTED tun0

Or

Wed Sep 26 15:10:49 2018 daemon.info glorytun[5092]: STOPPED tun0
Wed Sep 26 15:10:49 2018 daemon.err /usr/bin/ss-redir[6172]: remote recv: Connection refused
Wed Sep 26 15:10:49 2018 daemon.err /usr/bin/ss-redir[6171]: remote recv: Connection refused
Wed Sep 26 15:10:49 2018 daemon.err /usr/bin/ss-redir[6170]: remote recv: Connection refused
Wed Sep 26 15:10:49 2018 daemon.err /usr/bin/ss-redir[6171]: remote recv: Connection refused
Wed Sep 26 15:10:49 2018 daemon.err /usr/bin/ss-redir[6171]: remote recv: Connection refused
Wed Sep 26 15:10:49 2018 daemon.err /usr/bin/ss-redir[6170]: remote recv: Connection refused
Wed Sep 26 15:10:49 2018 daemon.err /usr/bin/ss-redir[6171]: remote recv: Connection refused
Wed Sep 26 15:10:49 2018 daemon.err /usr/bin/ss-redir[6170]: remote recv: Connection refused
Wed Sep 26 15:10:49 2018 daemon.err /usr/bin/ss-redir[6171]: remote recv: Connection refused
Wed Sep 26 15:10:49 2018 daemon.err /usr/bin/ss-redir[6170]: remote recv: Connection refused
Wed Sep 26 15:10:49 2018 daemon.err /usr/bin/ss-redir[6172]: remote recv: Connection refused
Wed Sep 26 15:10:49 2018 daemon.err /usr/bin/ss-redir[6172]: remote recv: Connection refused
Wed Sep 26 15:10:49 2018 daemon.err /usr/bin/ss-redir[6172]: remote recv: Connection refused
Wed Sep 26 15:10:49 2018 daemon.err /usr/bin/ss-redir[6171]: remote recv: Connection refused
Wed Sep 26 15:10:49 2018 daemon.err /usr/bin/ss-redir[6171]: remote recv: Connection refused
Wed Sep 26 15:10:49 2018 daemon.err /usr/bin/ss-redir[6172]: remote recv: Connection refused
Wed Sep 26 15:10:49 2018 daemon.err /usr/bin/ss-redir[6171]: remote recv: Connection refused
Wed Sep 26 15:10:49 2018 daemon.err /usr/bin/ss-redir[6172]: remote recv: Connection refused
Wed Sep 26 15:10:49 2018 daemon.err /usr/bin/ss-redir[6171]: remote recv: Connection refused
Wed Sep 26 15:10:49 2018 daemon.err /usr/bin/ss-redir[6172]: remote recv: Connection refused
Wed Sep 26 15:10:49 2018 daemon.err /usr/bin/ss-redir[6172]: remote recv: Connection refused
Wed Sep 26 15:10:49 2018 daemon.err /usr/bin/ss-redir[6171]: remote recv: Connection refused
Wed Sep 26 15:10:49 2018 daemon.err /usr/bin/ss-redir[6172]: remote recv: Connection refused
Wed Sep 26 15:10:49 2018 daemon.err /usr/bin/ss-redir[6170]: remote recv: Connection refused
Wed Sep 26 15:10:49 2018 daemon.err /usr/bin/ss-redir[6171]: remote recv: Connection refused
Wed Sep 26 15:10:50 2018 daemon.err /usr/bin/ss-redir[6170]: remote recv: Connection refused
Wed Sep 26 15:10:50 2018 daemon.err /usr/bin/ss-redir[6170]: remote recv: Connection refused
Wed Sep 26 15:10:50 2018 daemon.err /usr/bin/ss-redir[6170]: remote recv: Connection refused
Wed Sep 26 15:10:50 2018 daemon.err /usr/bin/ss-redir[6172]: remote recv: Connection refused
Wed Sep 26 15:10:50 2018 daemon.err /usr/bin/ss-redir[6171]: remote recv: Connection refused
Wed Sep 26 15:10:50 2018 daemon.err /usr/bin/ss-redir[6171]: remote recv: Connection refused
Wed Sep 26 15:10:50 2018 daemon.err /usr/bin/ss-redir[6172]: remote recv: Connection refused
Wed Sep 26 15:10:50 2018 daemon.err /usr/bin/ss-redir[6172]: getpeername: Socket not connected
Wed Sep 26 15:10:50 2018 daemon.err /usr/bin/ss-redir[6171]: remote recv: Connection refused
Wed Sep 26 15:10:50 2018 daemon.err /usr/bin/ss-redir[6171]: remote recv: Connection refused
Wed Sep 26 15:10:50 2018 daemon.err /usr/bin/ss-redir[6172]: remote recv: Connection refused
Wed Sep 26 15:10:50 2018 daemon.err /usr/bin/ss-redir[6171]: remote recv: Connection refused
Wed Sep 26 15:11:19 2018 daemon.err /usr/bin/ss-redir[6170]: remote recv: Connection refused
Wed Sep 26 15:11:19 2018 daemon.err /usr/bin/ss-redir[6171]: remote recv: Connection refused
Wed Sep 26 15:11:19 2018 daemon.err /usr/bin/ss-redir[6170]: remote recv: Connection refused
Wed Sep 26 15:11:19 2018 daemon.err /usr/bin/ss-redir[6170]: remote recv: Connection refused
Wed Sep 26 15:11:19 2018 daemon.err /usr/bin/ss-redir[6171]: remote recv: Connection refused
Wed Sep 26 15:11:19 2018 daemon.err /usr/bin/ss-redir[6171]: remote recv: Connection refused
Wed Sep 26 15:11:19 2018 daemon.err /usr/bin/ss-redir[6170]: remote recv: Connection refused
Wed Sep 26 15:11:19 2018 daemon.err /usr/bin/ss-redir[6170]: remote recv: Connection refused
Wed Sep 26 15:11:19 2018 daemon.err /usr/bin/ss-redir[6170]: remote recv: Connection refused
Wed Sep 26 15:11:19 2018 daemon.err /usr/bin/ss-redir[6172]: remote recv: Connection refused
Wed Sep 26 15:11:19 2018 daemon.err /usr/bin/ss-redir[6170]: remote recv: Connection refused
Wed Sep 26 15:11:19 2018 daemon.err /usr/bin/ss-redir[6172]: remote recv: Connection refused
Wed Sep 26 15:11:19 2018 daemon.err /usr/bin/ss-redir[6172]: remote recv: Connection refused
Wed Sep 26 15:11:20 2018 daemon.err /usr/bin/ss-redir[6170]: remote recv: Connection refused
Wed Sep 26 15:11:20 2018 daemon.err /usr/bin/ss-redir[6170]: remote recv: Connection refused
Wed Sep 26 15:11:20 2018 daemon.err /usr/bin/ss-redir[6171]: remote recv: Connection refused
Wed Sep 26 15:11:20 2018 daemon.err /usr/bin/ss-redir[6172]: remote recv: Connection refused
Wed Sep 26 15:11:20 2018 daemon.err /usr/bin/ss-redir[6171]: remote recv: Connection refused
Wed Sep 26 15:11:20 2018 daemon.err /usr/bin/ss-redir[6171]: remote recv: Connection refused
Wed Sep 26 15:11:20 2018 daemon.err /usr/bin/ss-redir[6172]: remote recv: Connection refused
Wed Sep 26 15:11:20 2018 daemon.err /usr/bin/ss-redir[6170]: remote recv: Connection refused
Wed Sep 26 15:11:20 2018 daemon.err /usr/bin/ss-redir[6170]: remote recv: Connection refused
Wed Sep 26 15:11:20 2018 daemon.err /usr/bin/ss-redir[6170]: remote recv: Connection refused
Wed Sep 26 15:11:20 2018 daemon.err /usr/bin/ss-redir[6172]: remote recv: Connection refused
Wed Sep 26 15:11:21 2018 daemon.err /usr/bin/ss-redir[6172]: remote recv: Connection refused
Wed Sep 26 15:11:21 2018 daemon.err /usr/bin/ss-redir[6172]: remote recv: Connection refused
Wed Sep 26 15:11:21 2018 daemon.err /usr/bin/ss-redir[6170]: remote recv: Connection refused
Wed Sep 26 15:11:21 2018 daemon.err /usr/bin/ss-redir[6171]: getpeername: Socket not connected
Wed Sep 26 15:11:21 2018 daemon.err /usr/bin/ss-redir[6171]: remote recv: Connection refused
Wed Sep 26 15:11:21 2018 daemon.err /usr/bin/ss-redir[6171]: remote recv: Connection refused
Wed Sep 26 15:11:21 2018 daemon.err /usr/bin/ss-local[6169]: getpeername: Socket not connected
Wed Sep 26 15:11:21 2018 daemon.err /usr/bin/ss-redir[6171]: remote recv: Connection refused
Wed Sep 26 15:11:21 2018 daemon.err /usr/bin/ss-redir[6171]: remote recv: Connection refused
Wed Sep 26 15:11:21 2018 daemon.err /usr/bin/ss-redir[6172]: remote recv: Connection refused
Wed Sep 26 15:11:21 2018 daemon.err /usr/bin/ss-redir[6170]: remote recv: Connection refused
Wed Sep 26 15:11:21 2018 daemon.err /usr/bin/ss-redir[6171]: remote recv: Connection refused
Wed Sep 26 15:11:21 2018 daemon.err /usr/bin/ss-redir[6172]: remote recv: Connection refused
Wed Sep 26 15:11:21 2018 daemon.err /usr/bin/ss-redir[6172]: remote recv: Connection refused
Wed Sep 26 15:11:21 2018 daemon.err /usr/bin/ss-redir[6172]: remote recv: Connection refused
Wed Sep 26 15:11:21 2018 daemon.err /usr/bin/ss-redir[6172]: remote recv: Connection refused
Wed Sep 26 15:11:21 2018 daemon.err /usr/bin/ss-redir[6170]: remote recv: Connection refused
Wed Sep 26 15:11:21 2018 daemon.err /usr/bin/ss-redir[6172]: remote recv: Connection refused
Wed Sep 26 15:11:21 2018 daemon.err /usr/bin/ss-redir[6171]: remote recv: Connection refused
Wed Sep 26 15:11:21 2018 daemon.err /usr/bin/ss-redir[6170]: remote recv: Connection refused
Wed Sep 26 15:11:21 2018 daemon.err /usr/bin/ss-redir[6171]: remote recv: Connection refused
Ysurac commented 5 years ago

For glorytun there is a "read: Operation timed out", then it try to reconnect and this seems to take 60s after a failure. For ss-redir, it receive a "Connection refused" from remote host.

If it's both the same time this seems to be a connection problem between OpenMPTCProuter and the VPS. I will increase timeout in next release.

fnoir commented 5 years ago

I reinstall the VPS. I monitor it to see if any anomalies are still occurring

fnoir commented 5 years ago

After many tests: