Openvpn256 failed to connect |
||||||||||||||
Issue descriptionOpenvpn256 failed to connect on DUT - Soraka, on M66-10452.54.0 Feedback report on Soraka - https://listnr.corp.google.com/report/85302955458
,
Apr 12 2018
This was separated from issue 817617 (a different VPN configuration bug)
,
Apr 12 2018
From issue 817617#21 :
The primary issue is that it can't resolve the hostname "openvpn256":
2018-04-11T16:06:18.539655-07:00 INFO shill[1151]: [INFO:openvpn_driver.cc(322)] OpenVPN process options: client,tls-client,remote openvpn256,nobind,persist-key,persist-tun,dev tun0,dev-type tun,syslog,proto tcp,port 1194,auth-retry interact,ca /run/shill/certificate_export/.org.chromium.Chromium.uK029v,auth-user-pass,remote-cert-tls server,management <IPv4: 25> 36855,management-client,management-hold,management-query-passwords,setenv SHILL_TASK_SERVICE :1.5,setenv SHILL_TASK_SERVICE :1.5,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
2018-04-11T16:06:18.541517-07:00 INFO shill[1151]: [INFO:service.cc(312)] Suppressed autoconnect to service 1 (no endpoints)
2018-04-11T16:06:18.541610-07:00 INFO shill[1151]: [INFO:service.cc(312)] Suppressed autoconnect to service 2 (no endpoints)
2018-04-11T16:06:18.541664-07:00 INFO shill[1151]: [INFO:service.cc(312)] Suppressed autoconnect to service 45 (throttled)
2018-04-11T16:06:18.548399-07:00 NOTICE openvpn[7661]: OpenVPN 2.4.4 x86_64-cros-linux-gnu [SSL (OpenSSL)] [LZO] [EPOLL] [PKCS11] [MH/PKTINFO] [AEAD] built on Apr 10 2018
2018-04-11T16:06:18.548512-07:00 NOTICE openvpn[7661]: library versions: OpenSSL 1.0.2n 7 Dec 2017, LZO 2.06
2018-04-11T16:06:18.549193-07:00 INFO shill[1151]: [INFO:openvpn_management_server.cc(226)] >INFO:OpenVPN Management Interface Version 1 -- type 'help' for more info
2018-04-11T16:06:18.549289-07:00 INFO shill[1151]: [INFO:openvpn_management_server.cc(405)] Client waiting for hold release.
2018-04-11T16:06:18.549343-07:00 INFO shill[1151]: [INFO:openvpn_management_server.cc(154)] Releasing hold.
2018-04-11T16:06:18.552629-07:00 INFO shill[1151]: [INFO:openvpn_management_server.cc(417)] SUCCESS: real-time state notification set to ON
2018-04-11T16:06:18.591427-07:00 INFO shill[1151]: [INFO:openvpn_management_server.cc(417)] SUCCESS: hold release succeeded
2018-04-11T16:06:18.591443-07:00 INFO shill[1151]: [INFO:openvpn_management_server.cc(236)] Processing need-password message.
2018-04-11T16:06:18.591453-07:00 INFO shill[1151]: [INFO:openvpn_management_server.cc(319)] Perform authentication: Auth
2018-04-11T16:06:18.591603-07:00 INFO shill[1151]: [INFO:openvpn_management_server.cc(417)] SUCCESS: 'Auth' username entered, but not yet verified
2018-04-11T16:06:18.591614-07:00 INFO shill[1151]: [INFO:openvpn_management_server.cc(417)] SUCCESS: 'Auth' password entered, but not yet verified
2018-04-11T16:06:18.591654-07:00 WARNING openvpn[7661]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
2018-04-11T16:06:18.723173-07:00 ERR openvpn[7661]: RESOLVE: Cannot resolve host address: openvpn256:1194 (Name or service not known)
2018-04-11T16:06:18.852353-07:00 ERR openvpn[7661]: RESOLVE: Cannot resolve host address: openvpn256:1194 (Name or service not known)
2018-04-11T16:06:18.852393-07:00 WARNING openvpn[7661]: Could not determine IPv4/IPv6 protocol
2018-04-11T16:06:18.852418-07:00 NOTICE openvpn[7661]: NOTE: UID/GID downgrade will be delayed because of --client, --pull, or --up-delay
2018-04-11T16:06:18.852694-07:00 NOTICE openvpn[7661]: SIGUSR1[soft,init_instance] received, process restarting
2018-04-11T16:06:18.852823-07:00 INFO shill[1151]: [INFO:openvpn_management_server.cc(386)] OpenVPN state: RESOLVE
2018-04-11T16:06:18.852882-07:00 INFO shill[1151]: [INFO:openvpn_management_server.cc(386)] OpenVPN state: RESOLVE
2018-04-11T16:06:18.852960-07:00 INFO shill[1151]: [INFO:openvpn_management_server.cc(386)] OpenVPN state: RECONNECTING
2018-04-11T16:06:18.852992-07:00 INFO shill[1151]: [INFO:openvpn_driver.cc(987)] OnReconnecting(0)
2018-04-11T16:06:18.853250-07:00 INFO shill[1151]: [INFO:openvpn_management_server.cc(405)] Client waiting for hold release.
2018-04-11T16:06:18.853276-07:00 INFO shill[1151]: [INFO:openvpn_management_server.cc(154)] Releasing hold.
2018-04-11T16:06:18.853639-07:00 WARNING openvpn[7661]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
2018-04-11T16:06:18.853721-07:00 INFO shill[1151]: [INFO:openvpn_management_server.cc(417)] SUCCESS: hold release succeeded
2018-04-11T16:06:18.983421-07:00 ERR openvpn[7661]: RESOLVE: Cannot resolve host address: openvpn256:1194 (Name or service not known)
2018-04-11T16:06:19.110698-07:00 ERR openvpn[7661]: RESOLVE: Cannot resolve host address: openvpn256:1194 (Name or service not known)
2018-04-11T16:06:19.110734-07:00 WARNING openvpn[7661]: Could not determine IPv4/IPv6 protocol
2018-04-11T16:06:19.110988-07:00 NOTICE openvpn[7661]: SIGUSR1[soft,init_instance] received, process restarting
2018-04-11T16:06:19.111104-07:00 INFO shill[1151]: [INFO:openvpn_management_server.cc(386)] OpenVPN state: RESOLVE
2018-04-11T16:06:19.111162-07:00 INFO shill[1151]: [INFO:openvpn_management_server.cc(386)] OpenVPN state: RESOLVE
2018-04-11T16:06:19.111245-07:00 INFO shill[1151]: [INFO:openvpn_management_server.cc(386)] OpenVPN state: RECONNECTING
2018-04-11T16:06:19.111318-07:00 INFO shill[1151]: [INFO:openvpn_driver.cc(987)] OnReconnecting(0)
2018-04-11T16:06:19.111486-07:00 INFO shill[1151]: [INFO:openvpn_management_server.cc(405)] Client waiting for hold release.
2018-04-11T16:06:19.111515-07:00 INFO shill[1151]: [INFO:openvpn_management_server.cc(154)] Releasing hold.
2018-04-11T16:06:19.111870-07:00 WARNING openvpn[7661]: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts
2018-04-11T16:06:19.111915-07:00 INFO shill[1151]: [INFO:openvpn_management_server.cc(417)] SUCCESS: hold release succeeded
2018-04-11T16:06:19.244944-07:00 ERR openvpn[7661]: RESOLVE: Cannot resolve host address: openvpn256:1194 (Name or service not known)
2018-04-11T16:06:19.379441-07:00 ERR openvpn[7661]: RESOLVE: Cannot resolve host address: openvpn256:1194 (Name or service not known)
2018-04-11T16:06:19.379478-07:00 WARNING openvpn[7661]: Could not determine IPv4/IPv6 protocol
2018-04-11T16:06:19.379780-07:00 NOTICE openvpn[7661]: SIGUSR1[soft,init_instance] received, process restarting
The secondary issue is that it keeps retrying over and over again for a minute until it hits the timeout, rather than sending a sensible error message back to the user. This is a KI which I intend to fix.
It looks like there is no default search domain on this network, so you would need to provide a FQDN to OpenVPN:
"/device/wlan0": {
"Address": "f894c21e8bba",
"BgscanMethod": "simple",
"BgscanShortInterval": 30,
"BgscanSignalThreshold": -62,
"ForceWakeToScanTimer": false,
"IPConfigs": {
"/ipconfig/wlan0_13_dhcp": {
"AcceptedHostname": "",
"Address": "<IPv4: 24>9",
"Broadcast": "<IPv4: 34>55",
"Dhcpv6Addresses": [ ],
"Dhcpv6DelegatedPrefixes": [ ],
"DomainName": "",
"Gateway": "<IPv4: 23>",
"LeaseDurationSeconds": 86400.0,
"Method": "dhcp",
"Mtu": 0,
"NameServers": [ "<IPv4: 23>" ],
"PeerAddress": "",
"Prefixlen": 24,
"SearchDomains": [ ],
"VendorEncapsulatedOptions": [ ],
"WebProxyAutoDiscoveryUrl": "",
"iSNSOptionData": [ ]
},
"/ipconfig/wlan0_14_ip": {
"AcceptedHostname": "",
"Address": "<IPv6: 13>",
"Broadcast": "",
"Dhcpv6Addresses": [ ],
"Dhcpv6DelegatedPrefixes": [ ],
"DomainName": "",
"Gateway": "<IPv6: 12>",
"LeaseDurationSeconds": 0.0,
"Method": "ipv6",
"Mtu": 0,
"NameServers": [ "<IPv6: 11>" ],
"PeerAddress": "",
"Prefixlen": 64,
"SearchDomains": [ ],
"VendorEncapsulatedOptions": [ ],
"WebProxyAutoDiscoveryUrl": "",
"iSNSOptionData": [ ]
}
},
Maybe this means that DHCP is no longer providing it, or maybe it means that CrOS is not setting it up correctly.
Reassigning since this doesn't look like a problem on the Chrome side.
,
Apr 12 2018
,
Apr 16 2018
Tested on CHROMEOS_RELEASE_BUILDER_PATH=soraka-release/R66-10452.54.0 logs 018-04-16T11:43:47.433201-07:00 INFO shill[1155]: [INFO:openvpn_driver.cc(322)] OpenVPN process options: client,tls-client,remote openvpn256,nobind,persist-key,persist-tun,dev tun0,dev-type tun,syslog,proto tcp,port 1194,auth-retry interact,ca /run/shill/certificate_export/.org.chromium.Chromium.NRuiKy,auth-user-pass,pkcs11-providers libchaps.so,pkcs11-id 8EFF2A0FB476F8FBC5BE56F63F2CB45A4AB88FAD,remote-cert-tls server,management 127.0.0.1 43974,management-client,management-hold,management-query-passwords,setenv SHILL_TASK_SERVICE :1.3,setenv SHILL_TASK_SERVICE :1.3,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 2018-04-16T11:43:47.444213-07:00 NOTICE openvpn[5313]: OpenVPN 2.4.4 x86_64-cros-linux-gnu [SSL (OpenSSL)] [LZO] [EPOLL] [PKCS11] [MH/PKTINFO] [AEAD] built on Apr 10 2018 2018-04-16T11:43:47.444315-07:00 NOTICE openvpn[5313]: library versions: OpenSSL 1.0.2n 7 Dec 2017, LZO 2.06 Connection reset, due to incorrect certs 2018-04-16T11:43:48.537392-07:00 INFO shill[1155]: [INFO:openvpn_management_server.cc(386)] OpenVPN state: AUTH 2018-04-16T11:43:50.549291-07:00 ERR openvpn[5313]: Connection reset, restarting [0] 2018-04-16T11:43:50.549691-07:00 NOTICE openvpn[5313]: SIGUSR1[soft,connection-reset] received, process restarting 2018-04-16T11:43:50.550038-07:00 INFO shill[1155]: [INFO:openvpn_management_server.cc(386)] OpenVPN state: RECONNECTING This is an UI issue. OS does not save the correct user certificate for VPN and defaults to the first available user certificate in the dropdown. I can connect to openvpn256 on Soraka with R65-10323.67.0(stable).
,
Apr 16 2018
After disabling the "Disable settings based Network Configuration" flag in chrome://flags(using old UI), openvpn256 works on soraka-release/R66-10452.54.0
,
Apr 16 2018
"Disable settings based Network Configuration" is not going to be available much longer. Can you file a feedback report after a failure so that I can look at the logs? Alternatively attach the contents of chrome://device-log.
,
Apr 18 2018
Feedback report below, https://listnr.corp.google.com/report/85332391410 contents of chrome://device-log. https://paste.googleplex.com/6293264911040512
,
Apr 18 2018
Thanks! Could you connect with the old UI ("Disable settings based Network Configuration") and file a feedback report + attach device-log for comparison?
,
Apr 18 2018
As requested in #9, 1) contents of chrome://device-log. https://paste.googleplex.com/6266644972175360 2) feedback report https://listnr.corp.google.com/report/85332446196
,
Apr 18 2018
Could you describe exactly how this network is configured? It *looks* like: a) The network is initially configured from a policy or a config file b) When attempting to connect to the network the configuration is incomplete (no user cert) which opens the configuration dialog and then fails to connect (with the new UI) Please confirm. Also, does creating a new configuration from the UI succeed or fail?
,
Apr 18 2018
Also, could you check whether this is reproducible on 67?
,
Apr 18 2018
One more request: Could you reproduce the failure, go to chrome://device-log, and check 'Debug' and attach the contents? I think this is related to the ONC merge logic and that it only affects policy configured networks (I can tell because 'OpenVPN.AuthRetry' is specified in the configuration and we don't have any UI for that).
,
Apr 19 2018
Could you describe exactly how this network is configured? >> This service is configured through an policy. b) When attempting to connect to the network the configuration is incomplete (no user cert) which opens the configuration dialog and then fails to connect (with the new UI) >> Yes, no user cert. cernekee@ pointed out the following fields are missing in shill openvpn onc 1) OpenVPN.Pkcs11.ID 2) OpenVPN.Pkcs11.PIN Also, does creating a new configuration from the UI succeed or fail? >> Creating a new configuration manually, succeeds. As requested in #13, chrome:device-log https://paste.googleplex.com/5650100470677504 Will check on R67 and 66.0.3359.48 (10452.22.0- First beta build). If 10452.22.0 build does not see this issue, we would like to mark this as beta blocker.
,
Apr 19 2018
OK. I believe that this is (kind of) WAI, even though the previous UI was successful. (But we may want to change the WAI behavior). Generally, if an ONC policy does not explicitly list a property, it is assumed to be non user modifiable. We make exception for a handful of properties, but currently not for certs. i.e. this could be fixed by modifying the policy configuration to include entries for OpenVPN.Pkcs11.ID and OpenVPN.Pkcs11.PIN specifying "recommended" empty values, which would allow the user to modify them. I'll try to set up a repro tomorrow so that I can prepare a fix, assuming we think that is the correct behavior. +emaxx@ P.S. it looks like that paste got clipped.
,
Apr 19 2018
This should have all the chrome device-logs https://paste.googleplex.com/5170235921399808 Also reproducible on R66-10452.22.0, so keeping it as stable blocker.
,
Apr 20 2018
,
Apr 20 2018
OK, I can repro this with a managedchrome.com account. aashutoshk@ - can you check the following: 1. Navigate to chrome://policy 2. Click 'Show value' for 'OpenNetworkConfiguraiton' 3. Paste the contents here. Specifically I am interested in the value for VPN.OpenVPN.ClientCertType for openvpn256 (but the rest may also be helpful).
,
Apr 20 2018
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/0ab5ab4d5c1c6710b2817826f483ea6a4ced4564 commit 0ab5ab4d5c1c6710b2817826f483ea6a4ced4564 Author: Steven Bennetts <stevenjb@chromium.org> Date: Fri Apr 20 21:08:14 2018 ONC: Allow client cert properties from UI This includes some base::Value cleanup in the validation code. Bug: 832165 Cq-Include-Trybots: master.tryserver.chromium.linux:closure_compilation Change-Id: Id83fa0d88f6171011d7287d371a91974d14ecb78 Reviewed-on: https://chromium-review.googlesource.com/1022331 Reviewed-by: Toni Barzic <tbarzic@chromium.org> Commit-Queue: Steven Bennetts <stevenjb@chromium.org> Cr-Commit-Position: refs/heads/master@{#552467} [modify] https://crrev.com/0ab5ab4d5c1c6710b2817826f483ea6a4ced4564/chromeos/network/onc/onc_validator.cc [modify] https://crrev.com/0ab5ab4d5c1c6710b2817826f483ea6a4ced4564/chromeos/test/data/network/policy/policy_vpn_no_auth.onc [modify] https://crrev.com/0ab5ab4d5c1c6710b2817826f483ea6a4ced4564/chromeos/test/data/network/policy/policy_vpn_ui.json [modify] https://crrev.com/0ab5ab4d5c1c6710b2817826f483ea6a4ced4564/chromeos/test/data/network/policy/shill_policy_on_managed_vpn_plus_ui.json [modify] https://crrev.com/0ab5ab4d5c1c6710b2817826f483ea6a4ced4564/ui/webui/resources/cr_components/chromeos/network/network_config.js
,
Apr 20 2018
This should hopefully be fixed in ToT. Please verify.
,
Apr 20 2018
[Auto-generated comment by a script] We noticed that this issue is targeted for M-66; it appears the fix may have landed after branch point, meaning a merge might be required. Please confirm if a merge is required here - if so add Merge-Request-66 label, otherwise remove Merge-TBD label. Thanks.
,
Apr 25 2018
rpattumani@chromium.org, aashutoshk@chromium.org - can you verify this? I'd like to get this merged to 66 asap. I believe that the fix is quite safe, and have tested it locally as best as I am able without an actual configured VPN to test against. We'll need to merge this to 67 also.
,
Apr 25 2018
This bug requires manual review: Request affecting a post-stable build Please contact the milestone owner if you have questions. Owners: cmasso@(Android), cmasso@(iOS), josafat@(ChromeOS), abdulsyed@(Desktop) For more details visit https://www.chromium.org/issue-tracking/autotriage - Your friendly Sheriffbot
,
Apr 25 2018
Discussed with Steven, we'll not block initial M66 stable. It will be in second stable refresh after bake time in ToT and M67
,
Apr 25 2018
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/99c8d8b48e2e180386a06b182edcbd491a4e910f commit 99c8d8b48e2e180386a06b182edcbd491a4e910f Author: Steven Bennetts <stevenjb@chromium.org> Date: Wed Apr 25 00:44:16 2018 ONC: Allow client cert properties from UI This includes some base::Value cleanup in the validation code. TBR=stevenjb@chromium.org (cherry picked from commit 0ab5ab4d5c1c6710b2817826f483ea6a4ced4564) Bug: 832165 Cq-Include-Trybots: master.tryserver.chromium.linux:closure_compilation Change-Id: Id83fa0d88f6171011d7287d371a91974d14ecb78 Reviewed-on: https://chromium-review.googlesource.com/1022331 Reviewed-by: Toni Barzic <tbarzic@chromium.org> Commit-Queue: Steven Bennetts <stevenjb@chromium.org> Cr-Original-Commit-Position: refs/heads/master@{#552467} Reviewed-on: https://chromium-review.googlesource.com/1026985 Reviewed-by: Steven Bennetts <stevenjb@chromium.org> Cr-Commit-Position: refs/branch-heads/3396@{#278} Cr-Branched-From: 9ef2aa869bc7bc0c089e255d698cca6e47d6b038-refs/heads/master@{#550428} [modify] https://crrev.com/99c8d8b48e2e180386a06b182edcbd491a4e910f/chromeos/network/onc/onc_validator.cc [modify] https://crrev.com/99c8d8b48e2e180386a06b182edcbd491a4e910f/chromeos/test/data/network/policy/policy_vpn_no_auth.onc [modify] https://crrev.com/99c8d8b48e2e180386a06b182edcbd491a4e910f/chromeos/test/data/network/policy/policy_vpn_ui.json [modify] https://crrev.com/99c8d8b48e2e180386a06b182edcbd491a4e910f/chromeos/test/data/network/policy/shill_policy_on_managed_vpn_plus_ui.json [modify] https://crrev.com/99c8d8b48e2e180386a06b182edcbd491a4e910f/ui/webui/resources/cr_components/chromeos/network/network_config.js
,
Apr 25 2018
Working as expected on Candy M68-10614.0.0
,
Apr 25 2018
Woot! Thanks.
,
Apr 25 2018
CL for M-66 merge is here: https://chromium-review.googlesource.com/#/c/chromium/src/+/1028551 Holding off on verification on 67 to submit.
,
Apr 29 2018
Have we been able to verify this on 67? josafat@, when is the cutoff for the next stable release? This is pretty important to get into 66.
,
Apr 30 2018
I'm planning by eow, let's go ahead and merge as per tot verification, we can revert is something unexpected is seen in m67
,
Apr 30 2018
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/763172d91cee08a4e1906da3185283f2873820d0 commit 763172d91cee08a4e1906da3185283f2873820d0 Author: Steven Bennetts <stevenjb@chromium.org> Date: Mon Apr 30 23:53:38 2018 ONC: Allow client cert properties from UI This includes some base::Value cleanup in the validation code. TBR=stevenjb@chromium.org (cherry picked from commit 0ab5ab4d5c1c6710b2817826f483ea6a4ced4564) Bug: 832165 Cq-Include-Trybots: master.tryserver.chromium.linux:closure_compilation Change-Id: Id83fa0d88f6171011d7287d371a91974d14ecb78 Reviewed-on: https://chromium-review.googlesource.com/1022331 Reviewed-by: Toni Barzic <tbarzic@chromium.org> Commit-Queue: Steven Bennetts <stevenjb@chromium.org> Cr-Original-Commit-Position: refs/heads/master@{#552467} Reviewed-on: https://chromium-review.googlesource.com/1028551 Reviewed-by: Steven Bennetts <stevenjb@chromium.org> Cr-Commit-Position: refs/branch-heads/3359@{#779} Cr-Branched-From: 66afc5e5d10127546cc4b98b9117aff588b5e66b-refs/heads/master@{#540276} [modify] https://crrev.com/763172d91cee08a4e1906da3185283f2873820d0/chromeos/network/onc/onc_validator.cc [modify] https://crrev.com/763172d91cee08a4e1906da3185283f2873820d0/chromeos/test/data/network/policy/policy_vpn_no_auth.onc [modify] https://crrev.com/763172d91cee08a4e1906da3185283f2873820d0/chromeos/test/data/network/policy/policy_vpn_ui.json [modify] https://crrev.com/763172d91cee08a4e1906da3185283f2873820d0/chromeos/test/data/network/policy/shill_policy_on_managed_vpn_plus_ui.json [modify] https://crrev.com/763172d91cee08a4e1906da3185283f2873820d0/ui/webui/resources/cr_components/chromeos/network/network_config.js
,
May 4 2018
Verified this on M66 stable build 10452.85.0, 66.0.3359.158. Will verify on M-67 early next week, will re-open the defect if the issue still exists on M-67. |
||||||||||||||
►
Sign in to add a comment |
||||||||||||||
Comment 1 by steve...@chromium.org
, Apr 12 2018