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

Issue 867680 link

Starred by 2 users

Issue metadata

Status: Verified
Owner:
Closed: Aug 8
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 1
Type: Bug-Regression

Blocking:
issue 870076



Sign in to add a comment

UI disconnecting and connecting to VPN is very finicky in M69.

Project Member Reported by aashuto...@chromium.org, Jul 25

Issue description

Chrome Version: <From about:version: Google Chrome 10895.4.0, >
Chrome OS Version: <From about:version: Platform 69.0.3497.13>
Chrome OS Platform: <Santa/BabyMega>
<b>Network info: <network, encryption type, router model (if known)></b>

Please specify Cr-* of the system to which this bug/feature applies (add
the label below).

Steps To Reproduce:
(1) Connect/Disconnect  VPN Network


Actual Result:
1) Disconnect button for VPN is sometimes missing.
2) Other times, the Connect button is not active, and we see a network out of range error. 
Screenshots attached. Will update the steps, if I see a pattern. 
Feedback report: https://listnr.corp.google.com/report/85568118444 

I reproduced this issue only for policy fetched (Enterprise) users.
How frequently does this problem reproduce? (Always, sometimes, hard to
reproduce?)
20 percent of the time.

What is the impact to the user, and is there a workaround? If so, what is
it?
No workaround. 
User impact: User confusion. 

Please provide any additional information below. Attach a screen shot or
log if possible.
https://listnr.corp.google.com/report/85568118444 

For graphics-related bugs, please copy/paste the contents of the about:gpu
page at the end of this report.

 
Screenshot 2018-07-25 at 2.40.50 PM.png
276 KB View Download
Screenshot 2018-07-25 at 2.40.44 PM.png
189 KB View Download
Cc: briannorris@chromium.org mortonm@chromium.org kirtika@chromium.org
Cc: benchan@chromium.org
Is this something reproduced locally? Why is the feedback report missing 90% of the useful logs? I only see a few sections in it.
Correction : Chrome OS Platform: <Samus/BabyMega>
Why is the feedback report missing 90% of the useful logs? I only see a few sections in it.
>> I am not sure either, why it didn't capture all the logs.

Is this something reproduced locally? 
>> Yes, I have attached the logs from the samus machine. 

If the attached logs don't have the mentioned failure, I can try to reproduce the issue and recollect logs. 

debug-logs_20180725-170708.tgz
1.8 MB Download
Hmm, interesting. Looks like there were 19 times in those logs that the OpenVPN binary was started (between 1:27pm and 5:05pm on the 25th) and 16 of those times the binary was SIGTERM'ed by something else on the system like so: 


2018-07-25T17:05:44.682906-07:00 INFO shill[13885]: [INFO:openvpn_driver.cc(341)] OpenVPN command line args: --config /run/shill/openvpn_config/.org.chromium.Chromium.QyzPxu --setenv UV_PLAT Chrome OS --setenv UV_PLAT_REL 10895.4.0
2018-07-25T17:05:44.689883-07:00 NOTICE openvpn[17831]: OpenVPN 2.4.4 x86_64-cros-linux-gnu [SSL (OpenSSL)] [LZO] [EPOLL] [PKCS11] [MH/PKTINFO] [AEAD] built on Jul 24 2018

... snip ...

2018-07-25T17:05:47.440119-07:00 NOTICE openvpn[17831]: TUN/TAP device tun0 opened
2018-07-25T17:05:47.440356-07:00 NOTICE openvpn[17831]: /usr/lib64/shill/shims/openvpn-script tun0 1500 1543 10.9.0.10 10.9.0.9 init
2018-07-25T17:05:47.451056-07:00 INFO openvpn-script[17839]: [INFO:task_proxy.cc(36)] Notify(up, argcount: 47)
2018-07-25T17:05:47.451444-07:00 INFO shill[13885]: [INFO:openvpn_driver.cc(406)] IP configuration received: up
2018-07-25T17:05:47.451491-07:00 INFO shill[13885]: [INFO:openvpn_driver.cc(524)] No search domains provided.
2018-07-25T17:05:47.502347-07:00 NOTICE openvpn[17831]: GID set to openvpn
2018-07-25T17:05:47.502595-07:00 NOTICE openvpn[17831]: UID set to openvpn
2018-07-25T17:05:47.502630-07:00 NOTICE openvpn[17831]: Initialization Sequence Completed
2018-07-25T17:05:47.503297-07:00 INFO shill[13885]: [INFO:openvpn_management_server.cc(391)] OpenVPN state: GET_CONFIG -> CONNECTED (SUCCESS)
2018-07-25T17:05:49.037517-07:00 NOTICE openvpn[17831]: SIGTERM[soft,management-exit] received, process exiting


the other 3 times OpenVPN wasn't SIGTERM'ed it failed like this:

2018-07-25T15:46:40.727348-07:00 INFO shill[1572]: [INFO:openvpn_driver.cc(341)] OpenVPN command line args: --config /run/shill/openvpn_config/.org.chromium.Chromium.aK6wAf --setenv UV_PLAT Chrome OS --setenv UV_PLAT_REL 10895.4.0

... snip ...

2018-07-25T13:27:28.236673-07:00 NOTICE openvpn[26277]: GID set to openvpn
2018-07-25T13:27:28.236824-07:00 NOTICE openvpn[26277]: UID set to openvpn
2018-07-25T13:27:28.236837-07:00 NOTICE openvpn[26277]: Initialization Sequence Completed
2018-07-25T13:27:28.237233-07:00 INFO shill[1494]: [INFO:openvpn_management_server.cc(391)] OpenVPN state: GET_CONFIG -> CONNECTED (SUCCESS)
2018-07-25T13:27:44.981906-07:00 ERR shill[1494]: [ERROR:arp_client.cc(130)] Socket recvfrom failed: Resource temporarily unavailable
2018-07-25T13:28:45.500851-07:00 ERR shill[1494]: message repeated 3853120 times: [ [ERROR:arp_client.cc(130)] Socket recvfrom failed: Resource temporarily unavailable]
On second thought, seems like shill just kills OpenVPN after a bunch (in this case 50000) "Socket recvfrom failed: Resource temporarily unavailable" messages..

2018-07-25T15:38:49.383331-07:00 NOTICE openvpn[5671]: GID set to openvpn
2018-07-25T15:38:49.384105-07:00 NOTICE openvpn[5671]: UID set to openvpn
2018-07-25T15:38:49.384123-07:00 NOTICE openvpn[5671]: Initialization Sequence Completed
2018-07-25T15:38:49.384450-07:00 INFO shill[1572]: [INFO:service.cc(313)] Suppressed autoconnect to service 0 (not connectable)
2018-07-25T15:38:49.384647-07:00 INFO shill[1572]: [INFO:openvpn_management_server.cc(391)] OpenVPN state: GET_CONFIG -> CONNECTED (SUCCESS)
2018-07-25T15:38:54.494811-07:00 ERR shill[1572]: [ERROR:arp_client.cc(130)] Socket recvfrom failed: Resource temporarily unavailable
2018-07-25T15:38:55.086276-07:00 ERR shill[1572]: message repeated 50846 times: [ [ERROR:arp_client.cc(130)] Socket recvfrom failed: Resource temporarily unavailable]
2018-07-25T15:38:55.086319-07:00 INFO shill[1572]: [INFO:service.cc(331)] Disconnecting from service 47: D-Bus RPC
2018-07-25T15:38:55.086717-07:00 INFO shill[1572]: [INFO:rpc_task.cc(42)] RPCTask 1 destroyed.
2018-07-25T15:38:55.086772-07:00 NOTICE openvpn[5671]: SIGTERM[soft,management-exit] received, process exiting

This may be related to  issue 865184 

Labels: Enterprise-Triaged
Marking with Enterprise-Triaged since this seems to have enough people looking at it for it to move forward. Please remove the label if you need assistance in triaging it. Thanks.
seeing this issue on Santa(Coral) with 10895.9.0.

Feedback report@
https://listnr.corp.google.com/report/85577820874

Please see attached screenshot.
Screenshot 2018-07-31 at 10.09.57 AM.png
288 KB View Download
Not able to disconnect from vpn as there is no disconnect button from chrome://settings, if i try to disconnect from uber tray nothing happens.
Owner: mortonm@chromium.org
Status: Assigned (was: Untriaged)
mortonm@ - assigning this to you per #10. Please close the bug once fix is submitted and jmuppala@ will verify once the build with fix is available.
Project Member

Comment 12 by bugdroid1@chromium.org, Jul 31

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

commit 1709b45b60b9ea26114ba9643b0a22a5876c3ff6
Author: Micah Morton <mortonm@chromium.org>
Date: Tue Jul 31 23:37:25 2018

shill_login_user: Ensure shill user profile dir is owned by shill:shill

We need to chown this dir to be owned by shill:shill even if it already
exists, so that when we update CrOS devices to running shill as
shill:shill (instead of root:root), the dir gets updated to the correct
permissions.

BUG=chromium:867171, chromium:867685 , chromium:865184 , chromium:867680 , chromium:864874 , chromium:865789 , chromium:866041 , chromium:866559 , chromium:866961 
TEST=flash 10820 image to lulu device. log in as user. configure VPN
stuff. flash new 10888 image to lulu and update shill_login_user script.
login and notice that these problems go away.

Change-Id: Ib487d3a36a7b351887e5c101f1e797a0ab21c3b9
Reviewed-on: https://chromium-review.googlesource.com/1153841
Commit-Ready: Micah Morton <mortonm@chromium.org>
Tested-by: Micah Morton <mortonm@chromium.org>
Reviewed-by: Abhishek Bhardwaj <abhishekbh@chromium.org>
Reviewed-by: Micah Morton <mortonm@chromium.org>

[modify] https://crrev.com/1709b45b60b9ea26114ba9643b0a22a5876c3ff6/bin/shill_login_user

Blockedon: 870076
1) Network out of range error resolved.
2) Bottom panel VPN key icon does not reflect the correct connection status (Check screenshot). A Refresh (Closing and reopening the panel) is needed. 
https://listnr.corp.google.com/report/85580020440
Let me know if we should open a separate bug for #2

Tested on Eve M70 10928.0.0
Screenshot 2018-08-01 at 4.56.10 PM.png
1.1 MB View Download
Maybe rename this at least to better describe the remaining problem?

Status: Verified (was: Assigned)
Cannot reproduce this issue on latest M69-10895.18.0. I will open a separate issue if we see #14(line item#2) behavior in M70. Closing this as verified. 
Able to reproduce this on Nocturne (R70-10971.0.0), opening a new bug.
Blocking: 870076
Blockedon: -870076

Sign in to add a comment