New issue
Advanced search Search tips
Note: Color blocks (like or ) mean that a user may not be available. Tooltip shows the reason.

Issue 797058 link

Starred by 7 users

Issue metadata

Status: Verified
Owner:
Last visit > 30 days ago
Closed: Jan 2018
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 1
Type: Bug-Regression



Sign in to add a comment

VPN no longer works since updating to Chrome OS 64 Beta

Project Member Reported by kbleicher@chromium.org, Dec 21 2017

Issue description

Pasting from chromeos-discuss; Sameer can you assign,prioritize, etc.?

Submitted by: jselinger
https://groups.google.com/a/google.com/forum/#!topic/chromeos-discuss/SA3iOEy0KsM

I noticed that my personal OpenVPN stopped working after updating my HP Chromebook 13 (chell) to Chrome OS 64 Beta. Specifically what happens is that I can connect to the VPN, but within 1 minute of connecting all traffic will stop being routed - DNS requests time out, pings to 8.8.8.8 fail, etc. Other devices (Windows and Android) can use the same VPN without any problems, and this worked perfectly on Chrome OS 63 Beta (the problems started immediately after updating to Chrome OS 64 Beta).

I also tried connecting to the Google corporate OpenVPN and saw exactly the same thing - here's a continuous ping to 8.8.8.8 that started right after I connected to the Google corporate OpenVPN and began failing after about 45 seconds:

crosh> ping 8.8.8.8
PING 8.8.8.8 (8.8.8.8) 56(84) bytes of data.
64 bytes from 8.8.8.8: icmp_seq=1 ttl=54 time=11.2 ms
64 bytes from 8.8.8.8: icmp_seq=2 ttl=54 time=11.7 ms
64 bytes from 8.8.8.8: icmp_seq=3 ttl=54 time=11.3 ms
64 bytes from 8.8.8.8: icmp_seq=4 ttl=54 time=11.4 ms
64 bytes from 8.8.8.8: icmp_seq=5 ttl=54 time=10.6 ms
64 bytes from 8.8.8.8: icmp_seq=6 ttl=54 time=10.8 ms
64 bytes from 8.8.8.8: icmp_seq=7 ttl=54 time=11.6 ms
64 bytes from 8.8.8.8: icmp_seq=8 ttl=54 time=11.9 ms
64 bytes from 8.8.8.8: icmp_seq=9 ttl=54 time=11.4 ms
64 bytes from 8.8.8.8: icmp_seq=10 ttl=54 time=11.6 ms
64 bytes from 8.8.8.8: icmp_seq=11 ttl=54 time=10.9 ms
64 bytes from 8.8.8.8: icmp_seq=12 ttl=54 time=10.4 ms
64 bytes from 8.8.8.8: icmp_seq=13 ttl=54 time=11.6 ms
64 bytes from 8.8.8.8: icmp_seq=14 ttl=54 time=11.6 ms
64 bytes from 8.8.8.8: icmp_seq=15 ttl=54 time=10.8 ms
64 bytes from 8.8.8.8: icmp_seq=16 ttl=54 time=11.4 ms
64 bytes from 8.8.8.8: icmp_seq=17 ttl=54 time=11.5 ms
64 bytes from 8.8.8.8: icmp_seq=18 ttl=54 time=11.8 ms
64 bytes from 8.8.8.8: icmp_seq=19 ttl=54 time=11.8 ms
64 bytes from 8.8.8.8: icmp_seq=20 ttl=54 time=11.8 ms
64 bytes from 8.8.8.8: icmp_seq=21 ttl=54 time=12.1 ms
64 bytes from 8.8.8.8: icmp_seq=22 ttl=54 time=10.2 ms
64 bytes from 8.8.8.8: icmp_seq=23 ttl=54 time=12.0 ms
64 bytes from 8.8.8.8: icmp_seq=24 ttl=54 time=11.9 ms
64 bytes from 8.8.8.8: icmp_seq=25 ttl=54 time=11.7 ms
64 bytes from 8.8.8.8: icmp_seq=26 ttl=54 time=11.5 ms
64 bytes from 8.8.8.8: icmp_seq=27 ttl=54 time=10.8 ms
64 bytes from 8.8.8.8: icmp_seq=28 ttl=54 time=11.0 ms
64 bytes from 8.8.8.8: icmp_seq=29 ttl=54 time=12.0 ms
64 bytes from 8.8.8.8: icmp_seq=30 ttl=54 time=11.2 ms
64 bytes from 8.8.8.8: icmp_seq=31 ttl=54 time=11.9 ms
64 bytes from 8.8.8.8: icmp_seq=32 ttl=54 time=11.9 ms
64 bytes from 8.8.8.8: icmp_seq=33 ttl=54 time=11.2 ms
64 bytes from 8.8.8.8: icmp_seq=34 ttl=54 time=11.6 ms
64 bytes from 8.8.8.8: icmp_seq=35 ttl=54 time=10.8 ms
64 bytes from 8.8.8.8: icmp_seq=36 ttl=54 time=10.6 ms
64 bytes from 8.8.8.8: icmp_seq=37 ttl=54 time=9.94 ms
64 bytes from 8.8.8.8: icmp_seq=38 ttl=54 time=10.3 ms
64 bytes from 8.8.8.8: icmp_seq=39 ttl=54 time=9.79 ms
64 bytes from 8.8.8.8: icmp_seq=40 ttl=54 time=12.0 ms
64 bytes from 8.8.8.8: icmp_seq=41 ttl=54 time=9.79 ms
64 bytes from 8.8.8.8: icmp_seq=42 ttl=54 time=10.3 ms
64 bytes from 8.8.8.8: icmp_seq=43 ttl=54 time=10.6 ms
64 bytes from 8.8.8.8: icmp_seq=45 ttl=54 time=9.66 ms
^C
--- 8.8.8.8 ping statistics ---
74 packets transmitted, 44 received, 40% packet loss, time 73067ms
rtt min/avg/max/mdev = 9.662/11.218/12.146/0.685 ms

I sent feedback from my google.com account shortly after this happened, and that feedback is available here:

https://listnr.corp.google.com/report/84817288780

Is this a known issue? Thanks!



 
Labels: ReleaseBlock-Stable

Comment 2 by snanda@chromium.org, Dec 21 2017

Cc: snanda@chromium.org
Owner: cernekee@chromium.org
In the log I see a couple of auth failed errors (at least one of which happened after a server-side inactivity timeout):

2017-12-19T12:16:25.835665-08:00 INFO shill[1305]: [INFO:service.cc(312)] Suppressed autoconnect to service 1 (no endpoints)
2017-12-19T12:16:30.399523-08:00 NOTICE openvpn[4739]: GID set to openvpn
2017-12-19T12:16:30.399571-08:00 NOTICE openvpn[4739]: UID set to openvpn
2017-12-19T12:16:30.399582-08:00 NOTICE openvpn[4739]: Initialization Sequence Completed
2017-12-19T12:16:30.399733-08:00 INFO shill[1305]: [INFO:openvpn_management_server.cc(386)] OpenVPN state: CONNECTED
2017-12-19T12:16:34.153992-08:00 WARNING shill[1305]: [WARNING:traffic_monitor.cc(221)] Congested tx queues detected, out-of-credits?
2017-12-19T12:17:43.380490-08:00 NOTICE openvpn[4739]: [v.ext.google.com] Inactivity timeout (--ping-restart), restarting
2017-12-19T12:17:43.381278-08:00 NOTICE openvpn[4739]: SIGUSR1[soft,ping-restart] received, process restarting
2017-12-19T12:17:43.381775-08:00 INFO shill[1305]: [INFO:openvpn_management_server.cc(386)] OpenVPN state: RECONNECTING
2017-12-19T12:17:43.381837-08:00 INFO shill[1305]: [INFO:openvpn_driver.cc(963)] OnReconnecting(0)
2017-12-19T12:17:43.381874-08:00 INFO shill[1305]: [INFO:vpn_driver.cc(273)] Schedule VPN connect timeout: 60 seconds.
2017-12-19T12:17:43.381965-08:00 INFO shill[1305]: [INFO:service.cc(398)] Service 13: state Online -> Configuring
2017-12-19T12:17:43.382021-08:00 INFO shill[1305]: [INFO:manager.cc(1459)] Service 13 updated; state: Configuring failure Unknown
2017-12-19T12:17:43.383454-08:00 INFO shill[1305]: [INFO:connection.cc(71)] 13: unbound from connection: tun0
2017-12-19T12:17:43.388638-08:00 INFO shill[1305]: [INFO:service.cc(312)] Suppressed autoconnect to service 11 (no endpoints)
2017-12-19T12:17:43.388669-08:00 INFO shill[1305]: [INFO:service.cc(312)] Suppressed autoconnect to service 12 (no endpoints)
2017-12-19T12:17:43.388688-08:00 INFO shill[1305]: [INFO:service.cc(312)] Suppressed autoconnect to service 0 (no endpoints)
2017-12-19T12:17:43.388703-08:00 INFO shill[1305]: [INFO:service.cc(312)] Suppressed autoconnect to service 1 (no endpoints)
2017-12-19T12:17:43.388769-08:00 INFO shill[1305]: [INFO:openvpn_management_server.cc(405)] Client waiting for hold release.
2017-12-19T12:17:43.388850-08:00 INFO shill[1305]: [INFO:openvpn_management_server.cc(154)] Releasing hold.
2017-12-19T12:17:43.389236-08:00 ERR shill[1305]: [ERROR:rtnl_handler.cc(293)] sequence 76 received error 3 (No such process)
2017-12-19T12:17:43.389360-08:00 ERR shill[1305]: [ERROR:rtnl_handler.cc(293)] sequence 77 received error 3 (No such process)
2017-12-19T12:17:43.389737-08:00 WARNING openvpn[4739]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
2017-12-19T12:17:43.389739-08:00 INFO shill[1305]: [INFO:openvpn_management_server.cc(417)] SUCCESS: hold release succeeded
2017-12-19T12:17:43.389960-08:00 NOTICE openvpn[4739]: TCP/UDP: Preserving recently used remote address: [AF_INET]<IPv4: 26>42:443
2017-12-19T12:17:43.390035-08:00 NOTICE openvpn[4739]: UDP link local: (not bound)
2017-12-19T12:17:43.390060-08:00 NOTICE openvpn[4739]: UDP link remote: [AF_INET]<IPv4: 26>42:443
2017-12-19T12:17:43.429449-08:00 INFO shill[1305]: [INFO:openvpn_management_server.cc(386)] OpenVPN state: WAIT
2017-12-19T12:17:44.041931-08:00 INFO shill[1305]: [INFO:openvpn_management_server.cc(386)] OpenVPN state: AUTH
2017-12-19T12:17:44.364484-08:00 NOTICE openvpn[4739]: peer info: IV_VER=2.4.3
2017-12-19T12:17:44.364529-08:00 NOTICE openvpn[4739]: peer info: IV_PLAT=linux
2017-12-19T12:17:44.364555-08:00 NOTICE openvpn[4739]: peer info: IV_PROTO=2
2017-12-19T12:17:44.364580-08:00 NOTICE openvpn[4739]: peer info: IV_NCP=2
2017-12-19T12:17:44.364605-08:00 NOTICE openvpn[4739]: peer info: IV_LZ4=1
2017-12-19T12:17:44.364630-08:00 NOTICE openvpn[4739]: peer info: IV_LZ4v2=1
2017-12-19T12:17:44.364655-08:00 NOTICE openvpn[4739]: peer info: IV_LZO=1
2017-12-19T12:17:44.364681-08:00 NOTICE openvpn[4739]: peer info: IV_COMP_STUB=1
2017-12-19T12:17:44.364709-08:00 NOTICE openvpn[4739]: peer info: IV_COMP_STUBv2=1
2017-12-19T12:17:44.364735-08:00 NOTICE openvpn[4739]: peer info: IV_TCPNL=1
2017-12-19T12:17:44.364763-08:00 NOTICE openvpn[4739]: peer info: IV_HWADDR=78:2b:cb:00:00:34
2017-12-19T12:17:44.364793-08:00 NOTICE openvpn[4739]: peer info: IV_SSL=OpenSSL_1.0.2l__25_May_2017
2017-12-19T12:17:44.365061-08:00 NOTICE openvpn[4739]: [v.ext.google.com] Peer Connection Initiated with [AF_INET]<IPv4: 26>42:443
2017-12-19T12:17:45.583787-08:00 INFO shill[1305]: [INFO:openvpn_management_server.cc(386)] OpenVPN state: GET_CONFIG
2017-12-19T12:17:45.591730-08:00 NOTICE openvpn[4739]: AUTH: Received control message: AUTH_FAILED,Incorrect username, password and/or OTP; please re-check them and try again
2017-12-19T12:17:45.599270-08:00 INFO shill[1305]: [INFO:openvpn_management_server.cc(350)] >PASSWORD:Verification Failed: 'Auth' ['Incorrect username, password and/or OTP; please re-check them and try again']
2017-12-19T12:17:45.599542-08:00 NOTICE openvpn[4739]: SIGUSR1[soft,auth-failure] received, process restarting
2017-12-19T12:17:45.599763-08:00 INFO shill[1305]: [INFO:rpc_task.cc(42)] RPCTask 0 destroyed.
2017-12-19T12:17:45.600017-08:00 INFO shill[1305]: [INFO:device.cc(1885)] Already in desired enable state.
2017-12-19T12:17:45.600060-08:00 INFO shill[1305]: [INFO:device.cc(206)] Device destructed: tun0 index 4
2017-12-19T12:17:45.600385-08:00 NOTICE openvpn[4739]: SIGTERM[hard,management-exit] received, process exiting


This one appears to be a manual disconnect coming from Chrome (dbus RPC):

2017-12-19T11:48:02.441315-08:00 INFO shill[1304]: [INFO:service.cc(319)] Connect to service 141: D-Bus RPC
2017-12-19T11:48:02.441394-08:00 INFO shill[1304]: [INFO:service.cc(398)] Service 141: state Failure -> Idle
2017-12-19T11:48:02.441768-08:00 INFO shill[1304]: [INFO:vpn_driver.cc(273)] Schedule VPN connect timeout: 60 seconds.
2017-12-19T11:48:02.441814-08:00 INFO shill[1304]: [INFO:service.cc(398)] Service 141: state Idle -> Configuring
2017-12-19T11:48:02.441854-08:00 INFO shill[1304]: [INFO:manager.cc(1459)] Service 141 updated; state: Configuring failure Unknown
2017-12-19T11:48:02.442865-08:00 INFO shill[1304]: [INFO:device.cc(201)] Device created: tun0 index 7
2017-12-19T11:48:02.443036-08:00 INFO shill[1304]: [INFO:rpc_task.cc(38)] RPCTask 1 created.
2017-12-19T11:48:02.443288-08:00 INFO shill[1304]: [INFO:openvpn_driver.cc(313)] OpenVPN process options: client,tls-client,remote us-siliconvalley.privateinternetaccess.com,nobind,persist-key,persist-tun,dev tun0,dev-type tun,syslog,proto udp,port 1194,auth-retry interact,comp-lzo,ca /run/shill/certificate_export/.org.chromium.Chromium.CsRRoQ,auth-user-pass,remote-cert-tls server,management <IPv4: 17> 45118,management-client,management-hold,management-query-passwords,setenv SHILL_TASK_SERVICE :1.9,setenv SHILL_TASK_SERVICE :1.9,setenv SHILL_TASK_PATH /task/1,script-security 2,up /usr/lib64/shill/shims/openvpn-script,up-restart,route-noexec,ifconfig-noexec,user openvpn,group openvpn
2017-12-19T11:48:02.445871-08:00 INFO shill[1304]: [INFO:service.cc(312)] Suppressed autoconnect to service 0 (no endpoints)
2017-12-19T11:48:02.445930-08:00 INFO shill[1304]: [INFO:service.cc(312)] Suppressed autoconnect to service 1 (no endpoints)
2017-12-19T11:48:02.451030-08:00 NOTICE openvpn[23249]: OpenVPN 2.4.4 x86_64-cros-linux-gnu [SSL (OpenSSL)] [LZO] [EPOLL] [PKCS11] [MH/PKTINFO] [AEAD] built on Dec 13 2017
2017-12-19T11:48:02.451050-08:00 NOTICE openvpn[23249]: library versions: OpenSSL 1.0.2k  26 Jan 2017, LZO 2.06
2017-12-19T11:48:02.451297-08:00 INFO shill[1304]: [INFO:openvpn_management_server.cc(226)] >INFO:OpenVPN Management Interface Version 1 -- type 'help' for more info
2017-12-19T11:48:02.451307-08:00 INFO shill[1304]: [INFO:openvpn_management_server.cc(405)] Client waiting for hold release.
2017-12-19T11:48:02.451312-08:00 INFO shill[1304]: [INFO:openvpn_management_server.cc(154)] Releasing hold.
2017-12-19T11:48:02.451338-08:00 INFO shill[1304]: [INFO:openvpn_management_server.cc(417)] SUCCESS: real-time state notification set to ON
2017-12-19T11:48:02.451355-08:00 INFO shill[1304]: [INFO:openvpn_management_server.cc(417)] SUCCESS: hold release succeeded
2017-12-19T11:48:02.491045-08:00 INFO shill[1304]: [INFO:openvpn_management_server.cc(236)] Processing need-password message.
2017-12-19T11:48:02.491073-08:00 INFO shill[1304]: [INFO:openvpn_management_server.cc(319)] Perform authentication: Auth
2017-12-19T11:48:02.491288-08:00 INFO shill[1304]: [INFO:openvpn_management_server.cc(417)] SUCCESS: 'Auth' username entered, but not yet verified
2017-12-19T11:48:02.491390-08:00 INFO shill[1304]: [INFO:openvpn_management_server.cc(417)] SUCCESS: 'Auth' password entered, but not yet verified
2017-12-19T11:48:02.491473-08:00 WARNING openvpn[23249]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
2017-12-19T11:48:02.500327-08:00 NOTICE openvpn[23249]: TCP/UDP: Preserving recently used remote address: [AF_INET]<IPv4: 21>61:1194
2017-12-19T11:48:02.500364-08:00 NOTICE openvpn[23249]: UDP link local: (not bound)
2017-12-19T11:48:02.500375-08:00 NOTICE openvpn[23249]: UDP link remote: [AF_INET]<IPv4: 21>61:1194
2017-12-19T11:48:02.500384-08:00 NOTICE openvpn[23249]: NOTE: UID/GID downgrade will be delayed because of --client, --pull, or --up-delay
2017-12-19T11:48:02.506823-08:00 WARNING openvpn[23249]: WARNING: this configuration may cache passwords in memory -- use the auth-nocache option to prevent this
2017-12-19T11:48:02.531383-08:00 INFO shill[1304]: [INFO:openvpn_management_server.cc(386)] OpenVPN state: RESOLVE
2017-12-19T11:48:02.531451-08:00 INFO shill[1304]: [INFO:openvpn_management_server.cc(386)] OpenVPN state: WAIT
2017-12-19T11:48:02.531494-08:00 INFO shill[1304]: [INFO:openvpn_management_server.cc(386)] OpenVPN state: AUTH
2017-12-19T11:48:02.578623-08:00 NOTICE openvpn[23249]: [7e93b8928ed812e908ff0b13ee1900de] Peer Connection Initiated with [AF_INET]<IPv4: 21>61:1194
2017-12-19T11:48:03.670482-08:00 INFO shill[1304]: [INFO:openvpn_management_server.cc(386)] OpenVPN state: GET_CONFIG
2017-12-19T11:48:03.684393-08:00 WARNING openvpn[23249]: WARNING: INSECURE cipher with block size less than 128 bit (64 bit).  This allows attacks like SWEET32.  Mitigate by using a --cipher with a larger block size (e.g. AES-256-CBC).
2017-12-19T11:48:03.684681-08:00 WARNING openvpn[23249]: WARNING: INSECURE cipher with block size less than 128 bit (64 bit).  This allows attacks like SWEET32.  Mitigate by using a --cipher with a larger block size (e.g. AES-256-CBC).
2017-12-19T11:48:03.684715-08:00 WARNING openvpn[23249]: WARNING: cipher with small block size in use, reducing reneg-bytes to 64MB to mitigate SWEET32 attacks.
2017-12-19T11:48:03.685350-08:00 NOTICE openvpn[23249]: TUN/TAP device tun0 opened
2017-12-19T11:48:03.685545-08:00 NOTICE openvpn[23249]: /usr/lib64/shill/shims/openvpn-script tun0 1500 1542 <IPv4: 24> <IPv4: 25> init
2017-12-19T11:48:03.704333-08:00 INFO openvpn-script[23251]: [INFO:task_proxy.cc(36)] Notify(up, argcount: 55)
2017-12-19T11:48:03.705540-08:00 INFO shill[1304]: [INFO:openvpn_driver.cc(373)] IP configuration received: up
2017-12-19T11:48:03.705634-08:00 WARNING shill[1304]: [WARNING:openvpn_driver.cc(545)] Unknown route option ignored: net_gateway
2017-12-19T11:48:03.705714-08:00 WARNING shill[1304]: [WARNING:openvpn_driver.cc(486)] No search domains provided.
2017-12-19T11:48:03.706590-08:00 INFO shill[1304]: [INFO:connection.cc(277)] UpdateFromIPConfig: Installing with parameters: local=<IPv4: 24> broadcast=<unknown> peer=<IPv4: 25> gateway=<IPv4: 25>
2017-12-19T11:48:03.707285-08:00 INFO shill[1304]: [INFO:connection.cc(78)] 141: bound to connection: tun0
2017-12-19T11:48:03.707445-08:00 INFO shill[1304]: [INFO:service.cc(398)] Service 141: state Configuring -> Connected
2017-12-19T11:48:03.734246-08:00 INFO shill[1304]: [INFO:manager.cc(1459)] Service 141 updated; state: Connected failure Unknown
2017-12-19T11:48:03.741503-08:00 INFO shill[1304]: [INFO:service.cc(398)] Service 141: state Connected -> Online
2017-12-19T11:48:03.741552-08:00 INFO shill[1304]: [INFO:manager.cc(1459)] Service 141 updated; state: Online failure Unknown
2017-12-19T11:48:03.750024-08:00 NOTICE openvpn[23249]: GID set to openvpn
2017-12-19T11:48:03.750087-08:00 NOTICE openvpn[23249]: UID set to openvpn
2017-12-19T11:48:03.750124-08:00 NOTICE openvpn[23249]: Initialization Sequence Completed
2017-12-19T11:48:03.752017-08:00 INFO shill[1304]: [INFO:openvpn_management_server.cc(364)] Auth-Token message ignored.
2017-12-19T11:48:03.752081-08:00 INFO shill[1304]: [INFO:openvpn_management_server.cc(386)] OpenVPN state: CONNECTED
2017-12-19T11:48:03.755389-08:00 INFO shill[1304]: [INFO:service.cc(312)] Suppressed autoconnect to service 0 (no endpoints)
2017-12-19T11:48:03.755438-08:00 INFO shill[1304]: [INFO:service.cc(312)] Suppressed autoconnect to service 1 (no endpoints)
2017-12-19T11:48:03.803741-08:00 WARNING arc-networkd[21124]: [WARNING:shill_client.cc(66)] Service properties is missing device path
2017-12-19T11:48:03.803799-08:00 INFO arc-networkd[21124]: [INFO:manager.cc(83)] Unbinding services
2017-12-19T11:48:15.001887-08:00 WARNING shill[1304]: [WARNING:traffic_monitor.cc(221)] Congested tx queues detected, out-of-credits?
2017-12-19T11:49:20.532469-08:00 INFO shill[1304]: [INFO:service.cc(330)] Disconnecting from service 141: D-Bus RPC
2017-12-19T11:49:20.532966-08:00 INFO shill[1304]: [INFO:rpc_task.cc(42)] RPCTask 1 destroyed.
2017-12-19T11:49:20.533641-08:00 INFO shill[1304]: [INFO:connection.cc(71)] 141: unbound from connection: tun0
2017-12-19T11:49:20.537129-08:00 INFO shill[1304]: [INFO:service.cc(398)] Service 141: state Online -> Idle
2017-12-19T11:49:20.537163-08:00 NOTICE openvpn[23249]: SIGTERM[soft,management-exit] received, process exiting

network_event_log doesn't go far enough back for me to tell what happened in Chrome.
Will someone update the group thread on this?  Probably good to get it back to the submitter and audience.
Cc: steve...@chromium.org
2017-12-19T12:17:43.380490-08:00 NOTICE openvpn[4739]: [v.ext.google.com] Inactivity timeout (--ping-restart), restarting
2017-12-19T12:17:43.381278-08:00 NOTICE openvpn[4739]: SIGUSR1[soft,ping-restart] received, process restarting

I see this on a dev channel caroline (M64 10176.13.1) connecting to corp OpenVPN.  Will try to figure out what's happening.
Cc: aashuto...@chromium.org harpreet@chromium.org dsunk...@chromium.org
This is reproducible on Eve M64-10176.22.0. Openvpn service fails, for me after about 15 secs. 

Comment 9 by cernekee@google.com, Dec 22 2017

Hmm, we did update to v2.4.4 of the openvpn package, but that happened back in M63.  That was  bug 774436 .
> I noticed that my personal OpenVPN stopped working

What is the `ping` parameter set to on the server side?

(I have the same question in to CorpEng.)

I noticed that on a local openvpn installation, the client-side `ping-restart` default (120) is not compatible with the server-side `ping` default (never).  So a simple setup like this will time out and reconnect every 120s:

server.conf:

    dev tun
    cipher AES-256-CBC

    topology net30
    server 192.168.20.0 255.255.255.0
    push "route 0.0.0.0 0.0.0.0"

    server-ipv6 2001:db8::/64

    ca cacert.pem
    cert cert-server.pem
    key cert-server.pem
    dh dh2048.pem

client.conf:

    remote 192.168.10.1
    dev tun
    cipher AES-256-CBC

    client
    ca cacert.pem
    cert cert-client.pem
    key cert-client.pem

Blockedon: 797597
crbug/797597 is tagged to M65 whereas this is set as a M64 blocker.  Should we reset this one to M65 as well?
I believe the claim is that M64 and M65 both have an issue with OpenVPN timeouts.  Not sure which label to apply (I never really paid much attention to them).

Bug 797597 is listed as a blocker because the current plan is:

1) Flash canary and enable verified boot
2) Corp-enroll the device
3) Run OpenVPN test, compare logs, etc.
4) Possibly add more debugging
5) Commit debug improvements to canary
6) Repeat

If I can specify `--verb 11` to OpenVPN, it will log details of the keepalive messages, which may help locate the root cause.  Currently it is tricky to enable verbose logging on a signed image.  And waiting to get the logging changes backported to M64 will slow down the debugging process.

I was hoping to start this process today.  I was counting on the attestation bug being fixed in canary, since it's been outstanding for a week.  Can we just revert the bad commit for now?
My vote would be to revert the bad commit if it fixes for M64.  The debugging is a great idea, but it that's not hitting til M65 let's revert and we can dig deeper later.
Cc: drcrash@chromium.org apronin@chromium.org
By "bad commit" I meant "whichever commit broke attestation."

As for the VPN problem reported in the OP: I saw it once on my caroline at home, but after flashing my bob to 64.0.3282.65 / 10176.34.0, corp openvpn has been up for over an hour.  I can surf the web and ping my workstation.  Are you still seeing the bug on M64?  Maybe it is sensitive to the wifi network you're on.

(I do see an issue with ARC++ traffic over CrOS VPN, will investigate that now.)
The commit which broke attestation only affects M65, not M64.
Also, the commit which broke attestation already has a fix for TPM 1.2 boards, and one is coming up for TPM 2.0 boards.

So one should be able to verify even now that on a machine like cernekee@'s Caroline, Open VPN issues, if any, aren't related to that attestation issue. (On his bob, though, he'll have to wait for the TPM 2.0 fix).
To clarify: the attestation issue is blocking me from getting a machine cert on canary channel, which is needed to connect to corp OpenVPN and test the latest builds.  It is not believed to be the root cause of the OpenVPN issue.

The caroline isn't a test device and I'm not planning to reimage it, but I can run some tests on another TPM 1.2 device.
Thanks for clarifying. CQ has been having various issues since this morning
(bad CLs in the batch, HWTest stages not running right now) so my CL for
TPM 2.0 is still trying to land...
kbleicher: Note that b/67430089 would really help with these sorts of issues, by removing our dependency on unmodified signed images to debug corp OpenVPN (and EAP-TLS, and SNAX) problems.  We're debugging with one hand tied behind our back.  Any thoughts on how to generate some traction on that request?
Blockedon: -797597 798924
#20, I weighed in on the bug; not sure if that will move it along.
Cc: -drcrash@chromium.org
Cc: -apronin@chromium.org abhishekbh@chromium.org ejcaruso@chromium.org mnissler@chromium.org jorgelo@chromium.org benchan@chromium.org
Labels: -Type-Bug -Pri-2 Pri-1 Type-Bug-Regression
Status: Started (was: Unconfirmed)
OK, it looks like we have a regression related to the routing changes in  bug 696865 .

Prior to the changes, the routing table would look something like then when an OpenVPN or L2TP/IPsec VPN is connected:

    # ip route list table main
    default via 10.0.0.1 dev tun0 metric 1
    default via 192.168.1.1 dev wlan0 metric 10
    192.168.1.0/24 dev wlan0 proto kernel scope link src 192.168.1.8

Packets destined for 192.168.1.x would be sent through wlan0 because of the longest match routing rule.  Packets destined for the internet (or other non-local hosts) would be sent through tun0 because it has the lowest metric.

But now, we use per-device routing tables for the builtin VPN clients:

    # ip rule list
    1:     from all lookup 1
    10:    from all lookup main
    32766: from all lookup main
    32767: from all lookup default

    # ip route list table 1
    default via 10.0.0.1 dev tun0 metric 1
    throw 1.2.3.4 scope link

    # ip route list table main
    default via 192.168.1.1 dev wlan0 metric 10
    192.168.1.0/24 dev wlan0 proto kernel scope link src 192.168.1.8

So according to the routing policy, table 1 (the dedicated routing table allocated for tun0) is consulted first.  Traffic to 1.2.3.4 (the VPN gateway) is sent back to the main table; but all other traffic, even traffic to the LAN addresses 192.168.1.x, is sent over the tunnel.  Unlike the case of third party VPNs, this applies to all traffic on the system, not just UID 1000.

This is a good thing if there is overlap between the LAN address range and the IP ranges on the VPN.  So if a user has to connect to the VPN to ssh to a machine 192.168.1.100 at work, this works as expected.

But there are two gotchas:

1) If the user has other devices on the LAN (like printers), they will be inaccesible when the VPN is connected.  In some cases, VPN administrators push split exclude routes to handle this situation.

2) Chrome OS currently enables the reverse path filter in strict mode.  This means that if a packet is received on wlan0, the kernel looks at the source address, runs it through the routing algorithm, and figures out if wlan0 is the best *egress* interface for that address.  If not, it drops the packet.

Our new policy routing scheme breaks the rp_filter logic, because the best egress interface for 192.168.1.x is now tun0.  Ordinarily this won't matter much for non-default interfaces in Chrome OS, because there won't be much inbound traffic on a non-default interface anyway.  But one important exception is for ARP: in this case, the rp_filter is causing ARP requests for the Chromebook to be silently discarded.  This results in the Chromebook "falling off the LAN" after about a minute.

This also seems to affect the arcbr0 interface, breaking ARC++ connectivity when a VPN is up.

(I couldn't actually reproduce this on corp, but on my home LAN it happened within a minute.)

My current line of thinking is that we should just enable loose routing globally.  We do plan to continue using per-device routing tables, as it is a prerequisite for proper multi-networking support.  In the M64 timeframe we probably do not want to push any more intrusive routing changes.

Another possibility is to change the routing policy so that OpenVPN and L2TP builtin clients only handle traffic for chronos/debugd traffic, just like third party VPNs.  This would force the ARP reverse path lookup to use the main table rather than the tun0 table.  But it would be a larger change in user-visible behavior.

Any preferences?

Cc: cernekee@chromium.org
 Issue 790897  has been merged into this issue.
Project Member

Comment 26 by bugdroid1@chromium.org, Jan 6 2018

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/overlays/chromiumos-overlay/+/d10e01ffc2da19335758e64d4a3f792afdc23359

commit d10e01ffc2da19335758e64d4a3f792afdc23359
Author: Kevin Cernekee <cernekee@chromium.org>
Date: Sat Jan 06 00:42:50 2018

chromeos-base: Enable loose reverse path filtering

When policy rules are used to route traffic over a builtin VPN (OpenVPN
or L2TP/IPsec), the kernel's FIB logic will use tun0 as the default
egress interface for all traffic that isn't destined for the VPN gateway.
If strict reverse path filtering is enabled, this means that inbound
ARP requests coming from the LAN router will be rejected
(since tun0 != wlan0), and the network will become unreachable when the
ARP entry for the Chromebook expires.

Since the current plan is to continue expanding the use of per-device
routing tables in order to support multi-routing APIs in Android, we will
need to keep loose filtering enabled indefinitely until we come up with
a way to make it work in this configuration.

BUG= chromium:797058 
TEST=manually verify using OpenVPN and L2TP/IPsec

Change-Id: Ib19f198f10fac792211354043542b02c5648ed9f
Reviewed-on: https://chromium-review.googlesource.com/851085
Commit-Ready: Kevin Cernekee <cernekee@chromium.org>
Tested-by: Kevin Cernekee <cernekee@chromium.org>
Reviewed-by: Kirtika Ruchandani <kirtika@chromium.org>

[modify] https://crrev.com/d10e01ffc2da19335758e64d4a3f792afdc23359/chromeos-base/chromeos-base/files/00-sysctl.conf
[rename] https://crrev.com/d10e01ffc2da19335758e64d4a3f792afdc23359/chromeos-base/chromeos-base/chromeos-base-0-r142.ebuild

Blockedon: -798924
Labels: Merge-Request-64
Status: Fixed (was: Started)
The fix seems to be working as intended on M65 canary 10284.0.0.  Requesting merge to M64.
Project Member

Comment 28 by sheriffbot@chromium.org, Jan 6 2018

Labels: -Merge-Request-64 Hotlist-Merge-Review Merge-Review-64
This bug requires manual review: M64 has already been promoted to the beta branch, so this requires manual review
Please contact the milestone owner if you have questions.
Owners: cmasso@(Android), cmasso@(iOS), kbleicher@(ChromeOS), abdulsyed@(Desktop)

For more details visit https://www.chromium.org/issue-tracking/autotriage - Your friendly Sheriffbot
Status: Started (was: Fixed)
> The fix seems to be working as intended

I take that back -- Android traffic is still not being handled correctly.  I thought that was an ARP problem but it's a routing issue instead.

NAT return traffic destined for 100.115.92.2 (which should be routed to arcbr0) is being sent back over the VPN tunnel.  So we're going to have to have a special routing rule for it.

It looks like Android uses a "uidrange 0-0" routing policy rule to make sure that kernel-generated traffic goes to the right table.  That solution probably won't work as-is for us, because some of the traffic that currently goes over builtin VPN tunnels (like from update_engine) originates in a root-owned process.  We've always had a problem differentiating UID 0 traffic from kernel-owned traffic.  It is less of an issue on Android because the parts of the Android OS that access the network mostly use UID 1000.

Easiest thing to do right now is to change the builtin OpenVPN + L2TP/IPsec clients so that they only route Chrome + Android traffic, aligning them with CrOS + ARC VPNs.  Here's the CL:

https://chromium-review.googlesource.com/#/c/aosp/platform/system/connectivity/shill/+/852645
Project Member

Comment 30 by bugdroid1@chromium.org, Jan 8 2018

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/4c2983b855bea01677755de8d83253fc1c72bc69

commit 4c2983b855bea01677755de8d83253fc1c72bc69
Author: Kevin Cernekee <cernekee@chromium.org>
Date: Mon Jan 08 19:32:19 2018

ONC: Plumb up OpenVPN.Verb property

This was only missing a translation table entry; it was otherwise
complete.

BUG= 797058 
TEST=manually import ONC file with "Verb": "11" and check net.log

Change-Id: Ic3be54945a0cc596c12fa849737a1d3dcaccc7de
Reviewed-on: https://chromium-review.googlesource.com/853229
Reviewed-by: Steven Bennetts <stevenjb@chromium.org>
Commit-Queue: Kevin Cernekee <cernekee@chromium.org>
Cr-Commit-Position: refs/heads/master@{#527711}
[modify] https://crrev.com/4c2983b855bea01677755de8d83253fc1c72bc69/chromeos/network/onc/onc_signature.cc
[modify] https://crrev.com/4c2983b855bea01677755de8d83253fc1c72bc69/chromeos/network/onc/onc_translation_tables.cc

Thanks Kevin; assume you're good for the merge at this point?
Project Member

Comment 32 by bugdroid1@chromium.org, Jan 9 2018

The following revision refers to this bug:
  https://chromium.googlesource.com/aosp/platform/system/connectivity/shill/+/439880eb0df598641c590a4dd97bde6b6e4e2570

commit 439880eb0df598641c590a4dd97bde6b6e4e2570
Author: Kevin Cernekee <cernekee@chromium.org>
Date: Tue Jan 09 09:04:42 2018

shill: Limit builtin VPNs to Chrome + Android traffic

The routing policy rule that unconditionally sends traffic over the
VPN tunnel is incorrectly matching: 1) ARP on the LAN; 2) packets
destined for 100.115.92.2 on arcbr0.  The easiest workaround is to
apply the same routing policy as is used for third-party VPN.

BUG= chromium:797058 
TEST=unit tests
TEST=manually test both OpenVPN + L2TP

Change-Id: I0a2f310ddac30a1b48ad83953162c76f67e73e21
Reviewed-on: https://chromium-review.googlesource.com/852645
Commit-Ready: Kevin Cernekee <cernekee@chromium.org>
Tested-by: Kevin Cernekee <cernekee@chromium.org>
Reviewed-by: Kevin Cernekee <cernekee@chromium.org>

[modify] https://crrev.com/439880eb0df598641c590a4dd97bde6b6e4e2570/ppp_device_unittest.cc
[modify] https://crrev.com/439880eb0df598641c590a4dd97bde6b6e4e2570/vpn/openvpn_driver.cc
[modify] https://crrev.com/439880eb0df598641c590a4dd97bde6b6e4e2570/vpn/l2tp_ipsec_driver.cc
[modify] https://crrev.com/439880eb0df598641c590a4dd97bde6b6e4e2570/vpn/third_party_vpn_driver_unittest.cc
[modify] https://crrev.com/439880eb0df598641c590a4dd97bde6b6e4e2570/vpn/vpn_provider.cc
[modify] https://crrev.com/439880eb0df598641c590a4dd97bde6b6e4e2570/vpn/openvpn_driver_unittest.cc
[modify] https://crrev.com/439880eb0df598641c590a4dd97bde6b6e4e2570/vpn/third_party_vpn_driver.cc
[modify] https://crrev.com/439880eb0df598641c590a4dd97bde6b6e4e2570/manager.h
[modify] https://crrev.com/439880eb0df598641c590a4dd97bde6b6e4e2570/vpn/vpn_provider.h
[modify] https://crrev.com/439880eb0df598641c590a4dd97bde6b6e4e2570/vpn/arc_vpn_driver_unittest.cc
[modify] https://crrev.com/439880eb0df598641c590a4dd97bde6b6e4e2570/vpn/l2tp_ipsec_driver_unittest.cc
[modify] https://crrev.com/439880eb0df598641c590a4dd97bde6b6e4e2570/ppp_device.cc
[modify] https://crrev.com/439880eb0df598641c590a4dd97bde6b6e4e2570/ppp_device.h
[modify] https://crrev.com/439880eb0df598641c590a4dd97bde6b6e4e2570/mock_ppp_device.h

Labels: -Merge-Review-64
Fix is verified in canary 10294.0.0, cherry-picking to M64.

https://chromium-review.googlesource.com/c/aosp/platform/system/connectivity/shill/+/857334
Project Member

Comment 34 by bugdroid1@chromium.org, Jan 9 2018

Labels: merge-merged-release-R64-10176.B
The following revision refers to this bug:
  https://chromium.googlesource.com/aosp/platform/system/connectivity/shill/+/9a20f518479833dbe69b18294944017d1b042ab3

commit 9a20f518479833dbe69b18294944017d1b042ab3
Author: Kevin Cernekee <cernekee@chromium.org>
Date: Tue Jan 09 22:07:24 2018

shill: Limit builtin VPNs to Chrome + Android traffic

The routing policy rule that unconditionally sends traffic over the
VPN tunnel is incorrectly matching: 1) ARP on the LAN; 2) packets
destined for 100.115.92.2 on arcbr0.  The easiest workaround is to
apply the same routing policy as is used for third-party VPN.

BUG= chromium:797058 
TEST=unit tests
TEST=manually test both OpenVPN + L2TP

Change-Id: I0a2f310ddac30a1b48ad83953162c76f67e73e21
Reviewed-on: https://chromium-review.googlesource.com/852645
Commit-Ready: Kevin Cernekee <cernekee@chromium.org>
Tested-by: Kevin Cernekee <cernekee@chromium.org>
Reviewed-by: Kevin Cernekee <cernekee@chromium.org>
(cherry picked from commit 439880eb0df598641c590a4dd97bde6b6e4e2570)

[modify] https://crrev.com/9a20f518479833dbe69b18294944017d1b042ab3/ppp_device_unittest.cc
[modify] https://crrev.com/9a20f518479833dbe69b18294944017d1b042ab3/vpn/openvpn_driver.cc
[modify] https://crrev.com/9a20f518479833dbe69b18294944017d1b042ab3/vpn/l2tp_ipsec_driver.cc
[modify] https://crrev.com/9a20f518479833dbe69b18294944017d1b042ab3/vpn/third_party_vpn_driver_unittest.cc
[modify] https://crrev.com/9a20f518479833dbe69b18294944017d1b042ab3/vpn/vpn_provider.cc
[modify] https://crrev.com/9a20f518479833dbe69b18294944017d1b042ab3/vpn/openvpn_driver_unittest.cc
[modify] https://crrev.com/9a20f518479833dbe69b18294944017d1b042ab3/vpn/third_party_vpn_driver.cc
[modify] https://crrev.com/9a20f518479833dbe69b18294944017d1b042ab3/manager.h
[modify] https://crrev.com/9a20f518479833dbe69b18294944017d1b042ab3/vpn/vpn_provider.h
[modify] https://crrev.com/9a20f518479833dbe69b18294944017d1b042ab3/vpn/arc_vpn_driver_unittest.cc
[modify] https://crrev.com/9a20f518479833dbe69b18294944017d1b042ab3/vpn/l2tp_ipsec_driver_unittest.cc
[modify] https://crrev.com/9a20f518479833dbe69b18294944017d1b042ab3/ppp_device.cc
[modify] https://crrev.com/9a20f518479833dbe69b18294944017d1b042ab3/ppp_device.h
[modify] https://crrev.com/9a20f518479833dbe69b18294944017d1b042ab3/mock_ppp_device.h

I can no longer ping the vpn gateway after updating to M64-10176.44.0 on Caroline. This is the build in which the fix landed. 
Rats, looks like we still need the rp_filter change in addition to the uidrange change.

Thanks Aashutosh for catching this right away.  I'll cherry pick to M64 now.

https://chromium-review.googlesource.com/c/chromiumos/overlays/chromiumos-overlay/+/852955
Project Member

Comment 37 by bugdroid1@chromium.org, Jan 11 2018

The following revision refers to this bug:
  https://chromium.googlesource.com/chromiumos/overlays/chromiumos-overlay/+/67d6bfcd491ec5987eb0abced36c0471ea1a929f

commit 67d6bfcd491ec5987eb0abced36c0471ea1a929f
Author: Kevin Cernekee <cernekee@chromium.org>
Date: Thu Jan 11 22:47:21 2018

chromeos-base: Enable loose reverse path filtering

When policy rules are used to route traffic over a builtin VPN (OpenVPN
or L2TP/IPsec), the kernel's FIB logic will use tun0 as the default
egress interface for all traffic that isn't destined for the VPN gateway.
If strict reverse path filtering is enabled, this means that inbound
ARP requests coming from the LAN router will be rejected
(since tun0 != wlan0), and the network will become unreachable when the
ARP entry for the Chromebook expires.

Since the current plan is to continue expanding the use of per-device
routing tables in order to support multi-routing APIs in Android, we will
need to keep loose filtering enabled indefinitely until we come up with
a way to make it work in this configuration.

BUG= chromium:797058 
TEST=manually verify using OpenVPN and L2TP/IPsec

Change-Id: Ib19f198f10fac792211354043542b02c5648ed9f
Reviewed-on: https://chromium-review.googlesource.com/851085
Commit-Ready: Kevin Cernekee <cernekee@chromium.org>
Tested-by: Kevin Cernekee <cernekee@chromium.org>
Reviewed-by: Kirtika Ruchandani <kirtika@chromium.org>
(cherry picked from commit d10e01ffc2da19335758e64d4a3f792afdc23359)
Reviewed-on: https://chromium-review.googlesource.com/852955
Reviewed-by: Kevin Cernekee <cernekee@chromium.org>
Commit-Queue: Kevin Cernekee <cernekee@chromium.org>

[modify] https://crrev.com/67d6bfcd491ec5987eb0abced36c0471ea1a929f/chromeos-base/chromeos-base/files/00-sysctl.conf
[rename] https://crrev.com/67d6bfcd491ec5987eb0abced36c0471ea1a929f/chromeos-base/chromeos-base/chromeos-base-0-r142.ebuild

Thanks so much for continuing to work on this, and sorry for my lack of responsiveness (I've been on holiday for the last 3 weeks). Please let me know if there's anything else you need from my side - I'm still seeing this issue on a Chell running 10176.41.0 but it sounds like that's expected since that build doesn't have the fixes yet.
Status: Fixed (was: Started)
This should be working in M64 + canary.  Ping me if not.
I can confirm that VPN works properly again on a Chell with M64 (platform 10176.47.0). Thanks!
Status: Verified (was: Fixed)
Closing this as verified. 

Sign in to add a comment