Client: Tons of "Login Failed" entries in owncloud-log, although logged in correctly
Hi,
my owncloud-logs are filled with false positive _Login failed_ error-messages.
Steps to reproduce
Leave oc desktop client for linux running.
Expected behaviour
There shouldn't be a _Login failed_ log entry when authentication obviously succeeded.
Actual behaviour
Lots of log entries containing _Login failed_ which will get me banned by _fail2ban_ instantly.
Server configuration
Operating system: raspbian stretch
Web server: nginx/1.10.3
Database: mariadb Ver 15.1 Distrib 10.1.23-MariaDB
PHP version: PHP 7.0.19-1
ownCloud version: 10.0.4
Where did you install ownCloud from: Installation via apt.
Signing status (ownCloud 9.0 and above):
No errors have been found.
Notice:
Since I've got _twofactor_totp_ enabled, I'm using app passwords.
List of activated apps:
Enabled:
- activity: 2.3.6
- announcementcenter: true
- bookmarks: 0.10.2
- calendar: 1.5.4
- checksum: 0.3.5
- comments: 0.3.0
- configreport: 0.1.1
- contacts: 1.5.3
- dav: 0.3.2
- external: 1.2
- federatedfilesharing: 0.3.1
- federation: 0.1.0
- files: 1.5.1
- files_antivirus: 0.11.2
- files_clipboard: 0.6.2
- files_external: 0.7.1
- files_external_dropbox: 1.0.0
- files_pdfviewer: 0.8.2
- files_sharing: 0.10.1
- files_texteditor: 2.2.1
- files_trashbin: 0.9.1
- files_versions: 1.3.0
- files_videoplayer: 0.9.8
- firstrunwizard: 1.1
- gallery: 16.0.2
- guests: 0.5.0
- impersonate: 0.1.2
- market: 0.2.3
- music: 0.5.5
- notes: 2.3.2
- notifications: 0.3.1
- ownbackup: 17.7.0
- passman: 2.1.4
- polls: 0.8.0
- provisioning_api: 0.5.0
- qownnotesapi: 17.7.0
- security: 0.0.2
- systemtags: 0.3.0
- tasks: 0.9.3
- templateeditor: 0.1
- twofactor_totp: 0.4.3
- updatenotification: 0.2.1
The content of config/config.php:
{
"system": {
"instanceid": "occvpbgpwcqr",
"passwordsalt": "***REMOVED SENSITIVE VALUE***",
"secret": "***REMOVED SENSITIVE VALUE***",
"trusted_domains": [
"*******",
"****************"
],
"datadirectory": "\/ownclouddata",
"overwrite.cli.url": "https:\/\/raspi02",
"dbtype": "mysql",
"version": "10.0.4.4",
"installed": true,
"forcessl": true,
"mail_smtpmode": "smtp",
"mail_smtpsecure": "tls",
"mail_smtpauthtype": "LOGIN",
"mail_smtpauth": 1,
"mail_smtphost": " smtp.1und1.de",
"mail_smtpport": "587",
"mail_smtpname": "***REMOVED SENSITIVE VALUE***",
"mail_smtppassword": "***REMOVED SENSITIVE VALUE***",
"mail_from_address": "owncloud",
"mail_domain": "***************",
"logtimezone": "Europe\/Berlin",
"loglevel": 0,
"logfile": "\/var\/log\/owncloud.log",
"session_lifetime": 624960,
"session_keepalive": true,
"remember_login_cookie_lifetime": 1296000,
"theme": "",
"maintenance": false,
"singleuser": false,
"dbname": "oc",
"dbhost": "localhost",
"dbuser": "***REMOVED SENSITIVE VALUE***",
"dbpassword": "***REMOVED SENSITIVE VALUE***",
"forceSSLforSubdomains": true,
"filelocking.enabled": true,
"memcache.local": "\\OC\\Memcache\\Redis",
"redis": {
"host": "localhost",
"port": 6379,
"password": "***REMOVED SENSITIVE VALUE***"
},
"memcache.locking": "\\OC\\Memcache\\Redis",
"appstore.experimental.enabled": true,
"trashbin_retention_obligation": "auto",
"updatechecker": false,
"htaccess.RewriteBase": "\/"
}
}
Are you using an external user-backend, if yes which one: OwnCloud Desktop Sync, OwnCloud for Android, CalDAV, CardDAV
Client configuration
Browser: Any
Operating system: Any
Logs
ownCloud log (data/owncloud.log)
...
{"reqId":"********************","level":2,"time":"2017-12-20T14:58:06+01:00","remoteAddr":"***.***.***.***","user":"******","app":"core","method":"PROPFIND","url":"/remote.php/dav/files/******/","message":"Login failed: '******' (Remote IP: '***.***.***.***')"}
{"reqId":"********************","level":2,"time":"2017-12-20T14:58:36+01:00","remoteAddr":"***.***.***.***","user":"******","app":"core","method":"PROPFIND","url":"/remote.php/dav/files/******/","message":"Login failed: '******' (Remote IP: '***.***.***.***')"}
{"reqId":"********************","level":2,"time":"2017-12-20T14:58:50+01:00","remoteAddr":"***.***.***.***","user":"******","app":"core","method":"GET","url":"/remote.php/dav/calendars/******/pers%C3%B6nlich/4f407995-90f4-4260-8a20-36c59a212814.1510000401224.ics","message":"Login failed: '******' (Remote IP: '***.***.***.***')"}
{"reqId":"********************","level":2,"time":"2017-12-20T14:58:50+01:00","remoteAddr":"***.***.***.***","user":"******","app":"core","method":"GET","url":"/remote.php/dav/calendars/******/familie/2fe57608-dfb8-463b-80dd-18a84e980dfe.1490854877969.ics","message":"Login failed: '******' (Remote IP: '***.***.***.***')"}
{"reqId":"********************","level":2,"time":"2017-12-20T14:58:51+01:00","remoteAddr":"***.***.***.***","user":"******","app":"core","method":"GET","url":"/remote.php/dav/calendars/******/pers%C3%B6nlich/156c33fd-3ab1-41b2-bec0-726be8a2ff9a.1510000400299.ics","message":"Login failed: '******' (Remote IP: '***.***.***.***')"}
{"reqId":"********************","level":2,"time":"2017-12-20T14:58:51+01:00","remoteAddr":"***.***.***.***","user":"******","app":"core","method":"GET","url":"/remote.php/dav/calendars/******/pers%C3%B6nlich/ownCloud-m9fh6x9laznymwskdgc4o.ics","message":"Login failed: '******' (Remote IP: '***.***.***.***')"}
{"reqId":"********************","level":2,"time":"2017-12-20T14:59:44+01:00","remoteAddr":"***.***.***.***","user":"******","app":"core","method":"REPORT","url":"/remote.php/dav/calendars/******/familie/","message":"Login failed: '******' (Remote IP: '***.***.***.***')"}
{"reqId":"********************","level":2,"time":"2017-12-20T14:59:45+01:00","remoteAddr":"***.***.***.***","user":"******","app":"core","method":"REPORT","url":"/remote.php/dav/calendars/******/vbm/","message":"Login failed: '******' (Remote IP: '***.***.***.***')"}
{"reqId":"********************","level":2,"time":"2017-12-20T15:01:32+01:00","remoteAddr":"***.***.***.***","user":"******","app":"core","method":"GET","url":"/ocs/v1.php/cloud/capabilities?format=json","message":"Login failed: '******' (Remote IP: '***.***.***.***')"}
{"reqId":"********************","level":2,"time":"2017-12-20T15:01:33+01:00","remoteAddr":"***.***.***.***","user":"******","app":"core","method":"GET","url":"/ocs/v1.php/cloud/user?format=json","message":"Login failed: '******' (Remote IP: '***.***.***.***')"}
{"reqId":"********************","level":2,"time":"2017-12-20T15:01:34+01:00","remoteAddr":"***.***.***.***","user":"******","app":"core","method":"GET","url":"/ocs/v1.php/cloud/activity?page=0&pagesize=100&format=json","message":"Login failed: '******' (Remote IP: '***.***.***.***')"}
{"reqId":"********************","level":2,"time":"2017-12-20T15:01:35+01:00","remoteAddr":"***.***.***.***","user":"******","app":"core","method":"GET","url":"/ocs/v2.php/apps/notifications/api/v1/notifications?format=json","message":"Login failed: '******' (Remote IP: '***.***.***.***')"}
{"reqId":"********************","level":2,"time":"2017-12-20T15:01:35+01:00","remoteAddr":"***.***.***.***","user":"******","app":"core","method":"PROPFIND","url":"/remote.php/dav/files/******/","message":"Login failed: '******' (Remote IP: '***.***.***.***')"}
{"reqId":"********************","level":2,"time":"2017-12-20T15:01:39+01:00","remoteAddr":"***.***.***.***","user":"******","app":"core","method":"PUT","url":"/remote.php/dav/files/******/Notes/Test-Note%2020.12..md","message":"Login failed: '******' (Remote IP: '***.***.***.***')"}
{"reqId":"********************","level":2,"time":"2017-12-20T15:02:29+01:00","remoteAddr":"***.***.***.***","user":"******","app":"core","method":"PROPFIND","url":"/remote.php/dav/files/******/","message":"Login failed: '******' (Remote IP: '***.***.***.***')"}
{"reqId":"********************","level":2,"time":"2017-12-20T15:02:30+01:00","remoteAddr":"***.***.***.***","user":"******","app":"core","method":"GET","url":"/ocs/v2.php/apps/notifications/api/v1/notifications?format=json","message":"Login failed: '******' (Remote IP: '***.***.***.***')"}
{"reqId":"********************","level":2,"time":"2017-12-20T15:02:30+01:00","remoteAddr":"***.***.***.***","user":"******","app":"core","method":"PROPFIND","url":"/remote.php/dav/files/******/","message":"Login failed: '******' (Remote IP: '***.***.***.***')"}
{"reqId":"********************","level":2,"time":"2017-12-20T15:02:31+01:00","remoteAddr":"***.***.***.***","user":"******","app":"core","method":"PROPFIND","url":"/remote.php/dav/files/******/Notes","message":"Login failed: '******' (Remote IP: '***.***.***.***')"}
{"reqId":"********************","level":2,"time":"2017-12-20T15:03:06+01:00","remoteAddr":"***.***.***.***","user":"******","app":"core","method":"PROPFIND","url":"/remote.php/dav/files/******/","message":"Login failed: '******' (Remote IP: '***.***.***.***')"}
{"reqId":"********************","level":2,"time":"2017-12-20T15:03:29+01:00","remoteAddr":"***.***.***.***","user":"******","app":"core","method":"PROPFIND","url":"/remote.php/dav/files/******/","message":"Login failed: '******' (Remote IP: '***.***.***.***')"}
{"reqId":"********************","level":2,"time":"2017-12-20T15:03:59+01:00","remoteAddr":"***.***.***.***","user":"******","app":"core","method":"PROPFIND","url":"/remote.php/dav/files/******/","message":"Login failed: '******' (Remote IP: '***.***.***.***')"}
{"reqId":"********************","level":2,"time":"2017-12-20T15:04:29+01:00","remoteAddr":"***.***.***.***","user":"******","app":"core","method":"PROPFIND","url":"/remote.php/dav/files/******/","message":"Login failed: '******' (Remote IP: '***.***.***.***')"}
...
Browser log
This happens when I'm using the OC desktop client.
treuss
All 28 comments
Hey @treuss, thanks for reporting!
This happens when I'm using the OC desktop client.
Can you send us the client logs from the time of the incident? Which version of the client are you using?
On your server logs I'm also seeing "Login failed" messages comming from /remote.php/dav/calendars/ endpoints; that shouldn't have anything to do with the Desktop client.
{"reqId":"********************","level":2,"time":"2017-12-20T14:58:50+01:00","remoteAddr":"***.***.***.***","user":"******","app":"core","method":"GET","url":"/remote.php/dav/calendars/******/pers%C3%B6nlich/4f407995-90f4-4260-8a20-36c59a212814.1510000401224.ics","message":"Login failed: '******' (Remote IP: '***.***.***.***')"}
SamuAlfageme
on 20 Dec 2017
Does your login don't work for the notifications api/endpoint? What do you use for login? username? mail? displayname?
michaelstingl
on 20 Dec 2017
@SamuAlfageme The client logs reveal lots of file-/dirnames but I didn't find any warnings or errors at all. It all looks very normal.
What parts of the logs would you need?
Edit:
I also use an app password f眉r caldav.
treuss
on 20 Dec 2017
@michaelstingl the login name is my username, which also might be my display name: treuss
There's no such thing as ldap or saml integration, only local users.
It also does confusing me that notifications api would throw login errors, especially when I'm obviously logged in....
treuss
on 20 Dec 2017
if you are using an e-mail address, maybe it can be related to this issue. https://github.com/owncloud/core/issues/28234
karakayasemi
on 20 Dec 2017
@karakayasemi thank you very much. Unfortunately, it is not the case, since I'm nit logging in using my email address.
treuss
on 20 Dec 2017
IMHO, If you able to debug, maybe you can just add debug log with username and password in here to see credentials is correct or not: https://github.com/owncloud/core/blob/master/lib/private/User/Session.php#L473. You can use this method to create log message.
```
\OCP\Util::writeLog('core', "$uid $password" , \OCP\Util::ERROR);
karakayasemi
on 20 Dec 2017
Some of the "Login failed" entries are caused by the client but others (like the calendars endpoint) aren't. That means this is very unlikely to be an issue in desktop client operation. Probably a server setup issue?
ckamm
on 5 Jan 2018
@karakayasemi thanks for the hint!
treuss
on 8 Jan 2018
@ckamm : CalDAV has working like a charm for the last 4 years. I guess I would experience some kind of trouble if a server misconfiguration was the issue here.
treuss
on 8 Jan 2018
@treuss there was a change to fix how sessions worked out for application passwords in 10.0.4: https://github.com/owncloud/core/issues/28553 -> https://github.com/owncloud/core/pull/28879
I believe clients (both desktop, CalDAV...) using old application passwords (for some reason not migrated to this new sessions-handling logic) might be behind all those login failed requests, all pilling up and causing the fail2ban to trigger. Did you upgrade from an 10.0.3 version before this happened?
SamuAlfageme
on 15 Jan 2018
@SamuAlfageme that sounds very plausible. I did indeed upgrade from 10.0.3. Not sure about the exact date though. It definitely must have been same week 10.0.4 was released.
So, I'll discard my old app-passwords, generate new ones and let you know if this does the trick.
Thanks again!
treuss
on 15 Jan 2018
I am also experiencing this same issue. Server log is flooded with "login failed" messages from the Linux desktop client, even though it's successfully syncing just fine. I upgraded from 10.0.3 to 10.0.4. I have tried re-generating the app passwords and using the new passwords in the desktop client, but this did not resolve the problem.
Edit: This is with the official Linux desktop client v2.4.0 (build 8911) on Fedora 26. The server is ownCloud 10.0.4 on CentOS 7 with PHP 5.6.
argon3030
on 15 Jan 2018
I can second @argon3030
Deleting and re-creating every single app-password didn't help.
treuss
on 16 Jan 2018
Just wanted to add fresh install using Bitnami AWS OwnCloud and we are seeing the exact same issues.
ownCloud 10.0.4 (stable)
ubuntu 14.04
Windows 7 Desktop running Client 2.4.0 (build 8894)
MichaelLeeHobbs
on 30 Jan 2018
Added this to the fail2ban conf to ignore the desktop app errors
ignoreregex={"reqId":".","level":2,"time":".","remoteAddr":".","user":".","app":"core","method":"GET|PROPFIND","url":".remote.php.|.\?format=json","message":"Login failed: '.' (Remote IP: '.*')"}
MichaelLeeHobbs
on 30 Jan 2018
It sounds to me like since 10.0.4 the server sometimes logs a "login failed" message even if the request succeeded.
@MichaelLeeHobbs @treuss @argon3030 as far as I understand your client synchronizes data successfully but you're nevertheless seeing these log messages. Could you verify by adding a small local file with a distinctive name, letting the client upload it, and then scanning for that PUT in your server logs? If this theory is correct then you should be seeing that file on the server but the log entry should say "Login failed" regardless.
This would also explain why we see this problem on CalDAV endpoints as well without observing any functionality issues.
ckamm
on 1 Feb 2018
@ckamm yes it is exactly as you describe. Everything syncing perfectly but tons of "login failed" in the log regardless.
From my PC:
[george@nostromo ownCloud]$ touch some-test-file
[george@nostromo ownCloud]$
And then on the server, in the log:
{"reqId":"cea1b9d7-e638-4890-84d0-006a9872de6c","level":2,"time":"2018-02-01T09:49:04-05:00","remoteAddr":"10.3.3.137","user":"george","app":"core","method":"PUT","url":"\/owncloud\/remote.php\/dav\/files\/george\/some-test-file","message":"Login failed: 'george' (Remote IP: '10.3.3.137')"}
The file was successfully sync'd to the server, and to all my PC's running the desktop client.
argon3030
on 1 Feb 2018
@argon3030 Is there also a success line for that PUT in the logs?
I agree with @SamuAlfageme: This looks a lot like owncloud/core#30157
ckamm
on 2 Feb 2018
@treuss @argon3030 @MichaelLeeHobbs see the latest info on the issue on https://github.com/owncloud/core/issues/30157
SamuAlfageme
on 2 Feb 2018
@ckamm No I do not see a success line. Here is the grep output from the entire server log on the unique "some-test-file" as used above. There is only the "login failed" PUT, and later when I delete the file from my PC, there is a "login failed" DELETE, and another error after that:
[root@cloud01 data]# cat owncloud.log | grep some-test-file
{"reqId":"cea1b9d7-e638-4890-84d0-006a9872de6c","level":2,"time":"2018-02-01T09:49:04-05:00","remoteAddr":"10.3.3.137","user":"george","app":"core","method":"PUT","url":"\/owncloud\/remote.php\/dav\/files\/george\/some-test-file","message":"Login failed: 'george' (Remote IP: '10.3.3.137')"}
{"reqId":"fdbb1c71-5335-4fe4-839f-2c1e078203c8","level":2,"time":"2018-02-01T10:01:03-05:00","remoteAddr":"10.3.3.137","user":"george","app":"core","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/george\/some-test-file","message":"Login failed: 'george' (Remote IP: '10.3.3.137')"}
{"reqId":"fdbb1c71-5335-4fe4-839f-2c1e078203c8","level":2,"time":"2018-02-01T10:01:04-05:00","remoteAddr":"10.3.3.137","user":"george","app":"dav","method":"DELETE","url":"\/owncloud\/remote.php\/dav\/files\/george\/some-test-file","message":"Could not get node for path: \"files\/george\/some-test-file\" : {$message}"}
[root@cloud01 data]#
Yet everything is working perfectly. Upon creating the file, it gets sync'd to the server and out to all my clients. And upon deleting the file from a client, it gets deleted from the server and from the other clients. Aside from the log entries, the actual behavior is perfect.
argon3030
on 2 Feb 2018
I updated yesterday from v10.0.4 to v10.0.6.1. Immediately after the update the OC log was filled with all those false positive logs.
- Cause: all Desktop Clients (Windows in my case), sync is still working
- I used app specific passwords
- When logging off in desktop client and logging in again, the OAuth 2.0 authentication is triggered. I grant access in the browser. For some minutes there weren麓t any log entries, now they are back. All desktop clients are using OAuth meanwhile, so the former app specific passwords are not in use anymore.
I麓m shocked there still is no solution for this issue after such a long time. Anything I/we "normal technical users" can contribute? Any developers around here? After taking more than 2 hours for the update a log flooding with false positives is very annoying... (off-topic: I really really really hate to say after so many years but... for me personal hearing from all friends and colleagues they don麓t have those issues and their updates are like "click and done" I think... it麓s time to take a closer look to Nextcloud. Better to spend once time for migration than fighting with all those issues.)
bcutter
on 4 Feb 2018
Additional information:
At Security / Sessions in profile I see a huge list of "browsers" (around 100 entries), 70 % of them:
MSFT-WIN-3/10.0.16299 (gzip)
It seems to match with the failed login entries in the OC log file.
bcutter
on 4 Feb 2018
Another weak and one exploding OC log file later... no response. Great support here.
bcutter
on 11 Feb 2018
Another week and one exploding OC log file later... no response. Great support here.
bcutter
on 11 Feb 2018
@bcutter As explained in previous comments, the hard work is going on in https://github.com/owncloud/core/issues/30157 and https://github.com/owncloud/QA/issues/529 .
michaelstingl
on 12 Feb 2018
Great support here.
@bcutter If you need enterprise support you can check https://owncloud.org/support/
guruz
on 12 Feb 2018
the hard work is going on in owncloud/core#30157 and owncloud/QA#529 .
Then let's close here :-)
guruz
on 12 Feb 2018
Related issues
tflidd
路
3Comments
xmana
路
5Comments
cdhowie
路
4Comments
ogasser
路
4Comments
guruz
路
4Comments