Hourly Login failed in owncloud.log

[wassereimer86]

Steps to reproduce

1. Unclear

Expected behaviour

No failed logins

Actual behaviour

Login failed messages in Log. Mostly hourly. Often at other times. From all users.

Server configuration

Operating system:
Ubuntu 22.04.2 LTS

Web server:
Apache

Database:
MariaDB 10.6.12

PHP version:
7.4.33

ownCloud version: (see ownCloud admin page)
10.11.0.6

Updated from an older ownCloud or fresh install:
Always updated as soon as new Version was available. Since years.

Where did you install ownCloud from:
Sources from Website

Signing status (ownCloud 9.0 and above):
No errors have been found.

The content of config/config.php:
https://gist.github.com/wassereimer86/b88e074850e24daa6d7f1dab5e7306f7

List of activated apps:
https://gist.github.com/wassereimer86/9f6ebb8b32ec8df457f4434d675c13fb

Are you using external storage, if yes which one: local/smb/sftp/...
no

Are you using encryption: yes/no
no

Are you using an external user-backend, if yes which one: LDAP/ActiveDirectory/Webdav/...
no

Client configuration

Not relevant because this happens to all users on different systems

Logs

Web server error log

Except for many "404 GET [/remote.php/dav/avatars/usernames/128.png] HTTP/1.0"" nothing interesting in there.

ownCloud log (data/owncloud.log)

Exemple:

{"reqId":"c680d52e-c283-4039-98e2-981a090b98c5","level":2,"time":"2023-04-28T10:28:57+02:00","remoteAddr":"***REMOVED SENSITIVE VALUE***","user":"***REMOVED SENSITIVE VALUE***","app":"core","method":"POST","url":"\/index.php\/apps\/oauth2\/api\/v1\/token","message":"Login failed: '***REMOVED SENSITIVE VALUE***' (Remote IP: '***REMOVED SENSITIVE VALUE***')"}
{"reqId":"7073cc71-224a-49e2-be05-47b26fa79a80","level":2,"time":"2023-04-28T11:28:58+02:00","remoteAddr":"***REMOVED SENSITIVE VALUE***","user":"***REMOVED SENSITIVE VALUE***","app":"core","method":"POST","url":"\/index.php\/apps\/oauth2\/api\/v1\/token","message":"Login failed: '***REMOVED SENSITIVE VALUE***' (Remote IP: '***REMOVED SENSITIVE VALUE***')"}
{"reqId":"3662e577-d5c1-4cff-8d31-bf4549e7593c","level":2,"time":"2023-04-28T12:28:59+02:00","remoteAddr":"***REMOVED SENSITIVE VALUE***","user":"***REMOVED SENSITIVE VALUE***","app":"core","method":"POST","url":"\/index.php\/apps\/oauth2\/api\/v1\/token","message":"Login failed: '***REMOVED SENSITIVE VALUE***' (Remote IP: '***REMOVED SENSITIVE VALUE***')"}
{"reqId":"e5ed8d79-0d4e-462a-9a45-277caee4e1dd","level":2,"time":"2023-04-28T13:29:30+02:00","remoteAddr":"***REMOVED SENSITIVE VALUE***","user":"***REMOVED SENSITIVE VALUE***","app":"core","method":"POST","url":"\/index.php\/apps\/oauth2\/api\/v1\/token","message":"Login failed: '***REMOVED SENSITIVE VALUE***' (Remote IP: '***REMOVED SENSITIVE VALUE***')"}
{"reqId":"538d7b50-f8c9-4e3e-bdb4-9bbf1cdce0bb","level":2,"time":"2023-04-28T14:30:01+02:00","remoteAddr":"***REMOVED SENSITIVE VALUE***,"user":"***REMOVED SENSITIVE VALUE***","app":"core","method":"POST","url":"\/index.php\/apps\/oauth2\/api\/v1\/token","message":"Login failed: '***REMOVED SENSITIVE VALUE***' (Remote IP: '***REMOVED SENSITIVE VALUE***')"}

Browser log

Not relevant because this happens to all users on different systems

[wassereimer86]

It's definitely the Windows Client. I activated logging and found it. But I don't know where exactly the problem is.

23-05-06 22:40:17:407 [ info gui.folder ]:	Trying to check "https://xxx/remote.php/dav/files/xxx/" for changes via ETag check. (time since last sync: 2749 s)
23-05-06 22:40:17:407 [ debug gui.folder.manager ]	[ OCC::FolderMan::slotRunOneEtagJob ]:	Scheduling "https://xxx/remote.php/dav/files/xxx/" to check remote ETag
23-05-06 22:40:17:407 [ info sync.httplogger ]:	"d262bd88-fc9c-4a33-abb2-cc783df8d2d3: Request: PROPFIND https://xxx/remote.php/dav/files/xxx/ Header: { Depth: 0, Prefer: return=minimal, Authorization: Bearer [redacted], User-Agent: Mozilla/5.0 (Windows) mirall/3.2.1.10355 (ownCloud, windows-10.0.22621 ClientArchitecture: x86_64 OsArchitecture: x86_64), Accept: */*, Content-Type: text/xml; charset=utf-8, X-Request-ID: d262bd88-fc9c-4a33-abb2-cc783df8d2d3, Original-Request-ID: d262bd88-fc9c-4a33-abb2-cc783df8d2d3, Content-Length: 108, Cookie: xxx; oc_sessionPassphrase=xxx, } Data: [<?xml version=\"1.0\" encoding=\"utf-8\"?><d:propfind xmlns:d=\"DAV:\"><d:prop><d:getetag/></d:prop></d:propfind>\n]"
23-05-06 22:40:17:407 [ info sync.networkjob ]:	Created OCC::RequestEtagJob(OCC::Account("xxx@xxx"), "https://xxx/remote.php/dav/files/xxx/", "PROPFIND", Original-Request-ID: "d262bd88-fc9c-4a33-abb2-cc783df8d2d3", X-Request-ID: "d262bd88-fc9c-4a33-abb2-cc783df8d2d3") for OCC::Folder(0x24d3e5ec1c0)
23-05-06 22:40:17:557 [ info sync.httplogger ]:	"d262bd88-fc9c-4a33-abb2-cc783df8d2d3: Response: PROPFIND 401 (Error: Der Host verlangt eine Authentifizierung,150ms) https://xxx/remote.php/dav/files/xxx/ Header: { Server: nginx, Date: Sat, 06 May 2023 20:40:17 GMT, Content-Type: application/xml; charset=utf-8, Transfer-Encoding: chunked, Connection: keep-alive, X-Powered-By: PHP/7.4.33, Expires: Thu, 19 Nov 1981 08:52:00 GMT, Cache-Control: no-store, no-cache, must-revalidate, Pragma: no-cache, Content-Security-Policy: default-src 'none';, WWW-Authenticate: Bearer realm=\"ownCloud\", Basic realm=\"ownCloud\", charset=\"UTF-8\", Set-Cookie: oc_sessionPassphrase=xxx; expires=Sat, 06-May-2023 21:00:17 GMT; Max-Age=1200; path=/; secure; HttpOnly; SameSite=Strict, X-Content-Type-Options: nosniff, X-XSS-Protection: 0, X-Robots-Tag: none, X-Frame-Options: SAMEORIGIN, X-Download-Options: noopen, X-Permitted-Cross-Domain-Policies: none, Strict-Transport-Security: max-age=15768000; includeSubDomains, } Data: [<?xml version=\"1.0\" encoding=\"utf-8\"?>\n<d:error xmlns:d=\"DAV:\" xmlns:s=\"http://sabredav.org/ns\">\n  <s:exception>Sabre\\DAV\\Exception\\NotAuthenticated</s:exception>\n  <s:message>No public access to this resource., Bearer token was incorrect, No 'Authorization: Basic' header found. Either the client didn't send one, or the server is misconfigured</s:message>\n</d:error>\n]"
23-05-06 22:40:17:557 [ debug sync.credentials.http ]	[ OCC::HttpCredentials::slotAuthentication ]:	void __cdecl OCC::HttpCredentials::slotAuthentication(class QNetworkReply *,class QAuthenticator *) QNetworkReplyHttpImpl(0x24d40f194d0)
23-05-06 22:40:17:557 [ warning sync.credentials.http ]:	Stop request: Authentication failed for  "https://xxx/remote.php/dav/files/xxx/" "d262bd88-fc9c-4a33-abb2-cc783df8d2d3"
23-05-06 22:40:17:557 [ info sync.credentials.http ]:	Refreshing token

[wassereimer86]

I am now testing if it is related to: https://doc.owncloud.com/server/next/admin_manual/troubleshooting/general_troubleshooting.html#owncloud-clients-cannot-connect-to-the-owncloud-server

[wassereimer86]

No, that wasn´t the solution. Still getting failed logins.

[wassereimer86]

Any ideas?

[VicDeo]

@wassereimer86 I guess the auth token is expiring and then being automatically refreshed by client.

[wassereimer86]

But that shouldn't result in failed Login Attempts, or?

[VicDeo]

Login attempt using expired oauth token is a failed login attempt.

[cortho]

@VicDeo how does this affect the brute_force_protection app?

Let's say a single user account has got a lots of clients connected on desktop computers and mobile devices and brute force settings are like https://doc.owncloud.com/server/next/admin_manual/configuration/server/security/brute_force_protection.html : ban after 3 failed login attempts within 60 seconds.

So if three of the clients have got expired oauth tokens within one minute all clients would be blocked?

[michaelstingl]

So if three of the clients have got expired oauth tokens within one minute all clients would be blocked?

Only when they're from the same originating IP address I'd say, but I have no prior experience with brut force protection, sorry.

I'd need to have a look at more lines in the desktop log. Posted lines doesn't include [ info sync.httplogger ] from the token renewal.

[github-actions]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed in 10 days if no further activity occurs. Thank you for your contributions.

[cortho]

It might be helpful for administrators to change the wording into e.g. "Token expired" so we can differ between actually failed logins and expired tokens

[github-actions]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed in 10 days if no further activity occurs. Thank you for your contributions.

[cortho]

Issue still relevant or close at least with "wontfix"