Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[OCIS/OAUTH] Windows client requesting login whenever computer awakens from deep sleep #11980

Open
2 tasks done
sfadschm opened this issue Nov 13, 2024 · 13 comments · May be fixed by #11984
Open
2 tasks done

[OCIS/OAUTH] Windows client requesting login whenever computer awakens from deep sleep #11980

sfadschm opened this issue Nov 13, 2024 · 13 comments · May be fixed by #11984
Assignees

Comments

@sfadschm
Copy link

Pre-submission Checks

  • I checked for similar issues, but could not find any. I also checked the closed issues. I could not contribute additional information to any existing issue.
  • I will take the time to fill in all the required fields. I know that the bug report may be dismissed otherwise due to lack of information.

Describe the bug

With the Windows client being connected to a live OCIS instance, the client request a new login via OAUTH / Browser whenever the computer awakes from deep sleep.
Here, "deep sleep" is my amateur description of what Windows11 does when you close the laptop lid and leave the computer in the sleep state for a longer time period.

Expected behavior

Credentials should be stored and not need to re-authenticate.

Steps to reproduce the issue

  1. Have ownCloud running and connected to an account on an OCIS instance on a Win11 laptop.
  2. Close the laptop lid to have the computer go to sleep.
  3. Wait until "deep sleep" sets in. (That is, if you open the lid again, you will not directly be prompted with the Win11 login screen, but with a sped-up booting procedure.)
  4. ownCloud client opens and states that the current account has been logged out.

Screenshots

No response

Logs

Log have been collected and I believe this is the crucial part right after the computer wakes up, leading to "OCC::ConnectionValidator::CredentialsNotReady":
https://gist.github.com/sfadschm/21d18d9306627f951f101d03625d6766

Client version number

ownCloud 5.3.1.14018 f15fd5
Libraries Qt 6.4.3, OpenSSL 3.1.2 1 Aug 2023
Using virtual files plugin: wincfapi
OS: windows-10.0.22631
QPA: windows

Desktop environment (Linux only)

No response

Client package version and origin (Linux only)

No response

Installation path (Windows only)

C:\Program Files\ownCloud

Server information

ownCloud Infinite Scale
Edition Community
Version 5.0.6
Web client version 8.0.4

on
Ubuntu 20.04.6 LTS

installed via
Docker container

Additional context

No response

@erikjv
Copy link
Collaborator

erikjv commented Nov 13, 2024

@sfadschm Can you include a bit more of the log file before that first line, so we can check what went on there? Also, what is the time of "sleep" and the "wake up" time?

@sfadschm
Copy link
Author

@erikjv Extended the gist accordingly. It looks like 8:33 was the time that the computer went into deep sleep. Before that, there is a long period of "Host XXX not found" log entries, likely because WLAN was inactive during sleep.
After waking up the computer on 10:59, we see some "Host not found" errors again, likely because it takes some time for the computer to reconnect to the WLAN network.

Unfortunately, there does not seem to be any indication in the Windows setting that tell after which time the OS goes into "deep sleep". "Closing the lid" is simply set to "sleep", yet behaviour differs depending on whether it is opened/woken up 30 mins later (no OC issue, Win11 password prompt shows up immediately) or after a longer time of ~2 h (OC logs out).

@sfadschm
Copy link
Author

sfadschm commented Nov 13, 2024

It appears that the "deep sleep" I was talking about is actually called "hibernate" in Windows. I will check BIOS setting to see if that is scheduled after a certain time of "sleep".

@sfadschm
Copy link
Author

Addendum:
Today the same behavior appeared after a normal sleep of about 30min. As far as I can tell for the first time.

Unfortunately, logs were turned off. Will add some more if it happens again.

@erikjv
Copy link
Collaborator

erikjv commented Nov 14, 2024

Next time it happens, can you include The last few (20?) lines before the ConnectionValidator::StatusNotFound messages?

@sfadschm
Copy link
Author

Updated the GIST again to include anything between the last "#### Discovery End ####" and the first "#### Discovery Start ####". The first "ConnectionValidator::StatusNotFound" appears on line 69.

Here goes the link again:
https://gist.github.com/sfadschm/21d18d9306627f951f101d03625d6766

Will add another gist when it appears again.

@erikjv
Copy link
Collaborator

erikjv commented Nov 15, 2024

What happens in sequence is:

  • when Windows wakes up, the network becomes available shortly after the applications are woken up (DHCP?)
  • also, when Windows goes back to sleep, the network disappears first before the applications are put to sleep (probably so they can handle any incomplete network requests)
  • then, when the last token refresh is long enough in the past, the authentication token needs refreshing
  • then, when this succeeded, the client tries to do a request using the new token
  • then, when the network disappears before any response has been received, and stays unavailable for the next 2 retries, the user is logged out:
24-11-13 07:48:22:404 [ debug sync.credentials.oauth ]  [ OCC::AccountBasedOAuth::fetchWellKnown ]:     starting CheckServerJob before fetching "/.well-known/openid-configuration"
24-11-13 07:48:22:451 [ info sync.httplogger ]: "74a8fb13-7452-4ce4-b0d6-f20e3880b950: Response: GET 0 (Error: Network unreachable,46ms) https://ocis.cloud.de/status.php Header: { } Data: []"
24-11-13 07:48:22:451 [ warning sync.checkserverjob ]:  error: status.php replied 0
24-11-13 07:48:22:451 [ debug sync.credentials.oauth ]  [ OCC::AccountBasedOAuth::fetchWellKnown::::operator() ]:       CheckServerJob failed, error: "Invalid HTTP status code received for status.php: 0"
24-11-13 07:48:22:451 [ warning sync.credentials.http ]:        Too many failed refreshes 3 -> log out

(The previous 2 attempts are in the log file right in front of this snippet.)

The fix is not to retry those jobs when there is no network available, or to not invalidate the credentials when the network disappeared.

@sfadschm
Copy link
Author

Thanks for the analysis ! The described sequence of events sounds like what Windows "modern standby" is intended to do, so seems legit.

Rechecking connection after a failed attempt seems like the more natural approach to me.

@sfadschm
Copy link
Author

Btw. What is the lifetime of the authentication token? Because this error on some days occured 3-5 times. Such short lifetime appears a little over the top on a first glance.

@erikjv erikjv linked a pull request Nov 18, 2024 that will close this issue
@DeepDiver1975
Copy link
Member

A draft fix has been implemented by @erikjv - feel free to grab the client from here - https://github.com/owncloud/client/actions/runs/11892365157?pr=11984

@erikjv
Copy link
Collaborator

erikjv commented Nov 20, 2024

Note: this also has a new feature that you might be interested in: in the settings there is now an option "Move remotely deleted files to the local trash bin instead of deleting them".

@sfadschm
Copy link
Author

Will test it for a few days and give feedback if the error occurs again. The implementation looks robust however.

The trash bin feature sounds great!

@sfadschm
Copy link
Author

No occurence so far.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants