Disabled users throw constant fatal frror in logs: `ServiceUnavailable` + `LoginException`

[eppfel]

I deactivated a user on my installation and this is also the only deactivated user. Apparently a device of said user is still configured to sync and therefore tries to log in. The server log shows fatal errors. If this is standard behaviour, I think that is a bug. Deactivating a user is a standard procedure. Hence a login attempt is not an error. Maybe it justifies some debug / ingo logging, but not to throw an exception.

(And the german "Benutzer deaktiviert" does not belong there either. ^^)

[webdav] Fatal: Sabre\DAV\Exception\ServiceUnavailable: OC\User\LoginException: Benutzer deaktiviert at <<closure>>

0. /var/www/virtual/eppcloud/html/3rdparty/sabre/dav/lib/DAV/Auth/Plugin.php line 193
   OCA\DAV\Connector\Sabre\Auth->check(Sabre\HTTP\Request {}, Sabre\HTTP\Response {})
1. /var/www/virtual/eppcloud/html/3rdparty/sabre/dav/lib/DAV/Auth/Plugin.php line 144
   Sabre\DAV\Auth\Plugin->check(Sabre\HTTP\Request {}, Sabre\HTTP\Response {})
2. /var/www/virtual/eppcloud/html/3rdparty/sabre/event/lib/WildcardEmitterTrait.php line 89
   Sabre\DAV\Auth\Plugin->beforeMethod(Sabre\HTTP\Request {}, Sabre\HTTP\Response {})
3. /var/www/virtual/eppcloud/html/3rdparty/sabre/dav/lib/DAV/Server.php line 458
   Sabre\DAV\Server->emit("beforeMethod:PROPFIND", [Sabre\HTTP\Requ ... }])
4. /var/www/virtual/eppcloud/html/3rdparty/sabre/dav/lib/DAV/Server.php line 251
   Sabre\DAV\Server->invokeMethod(Sabre\HTTP\Request {}, Sabre\HTTP\Response {})
5. /var/www/virtual/eppcloud/html/3rdparty/sabre/dav/lib/DAV/Server.php line 319
   Sabre\DAV\Server->start()
6. /var/www/virtual/eppcloud/html/apps/dav/lib/Server.php line 320
   Sabre\DAV\Server->exec()
7. /var/www/virtual/eppcloud/html/apps/dav/appinfo/v2/remote.php line 35
   OCA\DAV\Server->exec()
8. /var/www/virtual/eppcloud/html/remote.php line 167
   require_once("/var/www/virtua ... p")

PROPFIND /remote.php/dav/principals/users/[deactivated-user]/
from 2a01:c23:7c4f:8400:5415:34a9:5636:47ed at 2020-09-09T20:49:48+00:00

[no app in context] Error: OC\User\LoginException: Benutzer deaktiviert at <<closure>>

 0. /var/www/virtual/eppcloud/html/lib/private/User/Session.php line 617
    OC\User\Session->completeLogin("*** sensitive parameters replaced ***")
 1. /var/www/virtual/eppcloud/html/lib/private/User/Session.php line 366
    OC\User\Session->loginWithPassword("*** sensitive parameters replaced ***")
 2. /var/www/virtual/eppcloud/html/lib/private/User/Session.php line 459
    OC\User\Session->login("*** sensitive parameters replaced ***")
 3. /var/www/virtual/eppcloud/html/apps/dav/lib/Connector/Sabre/Auth.php line 131
    OC\User\Session->logClientIn("*** sensitive parameters replaced ***")
 4. /var/www/virtual/eppcloud/html/3rdparty/sabre/dav/lib/DAV/Auth/Backend/AbstractBasic.php line 106
    OCA\DAV\Connector\Sabre\Auth->validateUserPass("*** sensitive parameters replaced ***")
 5. /var/www/virtual/eppcloud/html/apps/dav/lib/Connector/Sabre/Auth.php line 254
    Sabre\DAV\Auth\Backend\AbstractBasic->check(Sabre\HTTP\Request {}, Sabre\HTTP\Response {})
 6. /var/www/virtual/eppcloud/html/apps/dav/lib/Connector/Sabre/Auth.php line 156
    OCA\DAV\Connector\Sabre\Auth->auth(Sabre\HTTP\Request {}, Sabre\HTTP\Response {})
 7. /var/www/virtual/eppcloud/html/3rdparty/sabre/dav/lib/DAV/Auth/Plugin.php line 193
    OCA\DAV\Connector\Sabre\Auth->check(Sabre\HTTP\Request {}, Sabre\HTTP\Response {})
 8. /var/www/virtual/eppcloud/html/3rdparty/sabre/dav/lib/DAV/Auth/Plugin.php line 144
    Sabre\DAV\Auth\Plugin->check(Sabre\HTTP\Request {}, Sabre\HTTP\Response {})
 9. /var/www/virtual/eppcloud/html/3rdparty/sabre/event/lib/WildcardEmitterTrait.php line 89
    Sabre\DAV\Auth\Plugin->beforeMethod(Sabre\HTTP\Request {}, Sabre\HTTP\Response {})
10. /var/www/virtual/eppcloud/html/3rdparty/sabre/dav/lib/DAV/Server.php line 458
    Sabre\DAV\Server->emit("beforeMethod:PROPFIND", [Sabre\HTTP\Requ ... }])
11. /var/www/virtual/eppcloud/html/3rdparty/sabre/dav/lib/DAV/Server.php line 251
    Sabre\DAV\Server->invokeMethod(Sabre\HTTP\Request {}, Sabre\HTTP\Response {})
12. /var/www/virtual/eppcloud/html/3rdparty/sabre/dav/lib/DAV/Server.php line 319
    Sabre\DAV\Server->start()
13. /var/www/virtual/eppcloud/html/apps/dav/lib/Server.php line 320
    Sabre\DAV\Server->exec()
14. /var/www/virtual/eppcloud/html/apps/dav/appinfo/v2/remote.php line 35
    OCA\DAV\Server->exec()
15. /var/www/virtual/eppcloud/html/remote.php line 167
    require_once("/var/www/virtua ... p")

PROPFIND /remote.php/dav/principals/users/[deactivated-user]/
from 2a01:c23:7c4f:8400:5415:34a9:5636:47ed at 2020-09-09T20:49:48+00:00

Server configuration detail

Operating system: Linux 2.6.32-754.15.3.el6.x86_64 #1 SMP Tue Jun 18 16:25:32 UTC 2019 x86_64

Webserver: Apache/2.2.15 (CentOS) (cgi-fcgi)

Database: mysql 5.1.73

PHP version: 7.2.31

Modules loaded: Core, date, libxml, openssl, pcre, sqlite3, zlib, bcmath, bz2, calendar, ctype, curl, dom, hash, fileinfo, filter, ftp, gd, gettext, gmp, SPL, iconv, session, intl, json, ldap, mbstring, standard, mysqlnd, pcntl, mysqli, PDO, pdo_mysql, pdo_pgsql, pdo_sqlite, pgsql, Phar, posix, pspell, Reflection, imap, shmop, SimpleXML, soap, sockets, exif, sysvmsg, sysvsem, sysvshm, tidy, tokenizer, xml, xmlreader, xmlrpc, xmlwriter, xsl, zip, cgi-fcgi, redis, imagick, Zend OPcache

Nextcloud version: 19.0.2 - 19.0.2.2

Updated from an older Nextcloud/ownCloud or fresh install: updated

Where did you install Nextcloud from: updater

Signing status

Array ( )

List of activated apps

Enabled: - accessibility: 1.5.0 - activity: 2.12.0 - admin_audit: 1.9.0 - bruteforcesettings: 2.0.1 - calendar: 2.0.4 - cloud_federation_api: 1.2.0 - comments: 1.9.0 - contacts: 3.3.0 - contactsinteraction: 1.0.0 - dav: 1.15.0 - federatedfilesharing: 1.9.0 - federation: 1.9.0 - files: 1.14.0 - files_external: 1.10.0 - files_pdfviewer: 1.8.0 - files_rightclick: 0.16.0 - files_sharing: 1.11.0 - files_trashbin: 1.9.0 - files_versions: 1.12.0 - files_videoplayer: 1.8.0 - firstrunwizard: 2.8.0 - logreader: 2.4.0 - lookup_server_connector: 1.7.0 - mail: 1.4.1 - nextcloud_announcements: 1.8.0 - notifications: 2.7.0 - oauth2: 1.7.0 - password_policy: 1.9.1 - photos: 1.1.0 - polls: 1.4.3 - privacy: 1.3.0 - provisioning_api: 1.9.0 - recommendations: 0.7.0 - serverinfo: 1.9.0 - settings: 1.1.0 - sharebymail: 1.9.0 - support: 1.2.1 - survey_client: 1.7.0 - tasks: 0.13.3 - text: 3.0.1 - theming: 1.10.0 - twofactor_backupcodes: 1.8.0 - twofactor_totp: 5.0.0 - twofactor_u2f: 6.0.0 - updatenotification: 1.9.0 - viewer: 1.3.0 - workflowengine: 2.1.0 Disabled: - encryption - files_markdown - news - notes - systemtags - user_ldap

Configuration (config/config.php)

{ "instanceid": "***REMOVED SENSITIVE VALUE***", "passwordsalt": "***REMOVED SENSITIVE VALUE***", "secret": "***REMOVED SENSITIVE VALUE***", "trusted_domains": [ "***REMOVED SENSITIVE VALUE***" ], "datadirectory": "***REMOVED SENSITIVE VALUE***", "dbtype": "mysql", "version": "19.0.2.2", "dbname": "***REMOVED SENSITIVE VALUE***", "dbhost": "***REMOVED SENSITIVE VALUE***", "dbtableprefix": "oc_", "dbuser": "***REMOVED SENSITIVE VALUE***", "dbpassword": "***REMOVED SENSITIVE VALUE***", "logtimezone": "UTC", "installed": true, "loglevel": 0, "filelocking.enabled": "true", "memcache.locking": "\\OC\\Memcache\\Redis", "memcache.local": "\\OC\\Memcache\\Redis", "redis": { "host": "***REMOVED SENSITIVE VALUE***", "port": 0, "timeout": 0 }, "forcessl": true, "mail_from_address": "***REMOVED SENSITIVE VALUE***", "mail_smtpmode": "smtp", "mail_domain": "***REMOVED SENSITIVE VALUE***", "maintenance": false, "updater.release.channel": "stable", "debug": false, "appstore.experimental.enabled": true, "theme": "", "log_rotate_size": 104857600, "overwrite.cli.url": "***REMOVED SENSITIVE VALUE***", "htaccess.RewriteBase": "\/", "htaccess.IgnoreFrontController": true, "mail_smtpsecure": "ssl", "mail_smtpauthtype": "LOGIN", "mail_smtpauth": 1, "mail_smtphost": "***REMOVED SENSITIVE VALUE***", "mail_smtpport": "465", "mail_smtpname": "***REMOVED SENSITIVE VALUE***", "mail_smtppassword": "***REMOVED SENSITIVE VALUE***", "twofactor_enforced": "true", "twofactor_enforced_groups": [ "admin" ], "twofactor_enforced_excluded_groups": [ "Familie", "test" ], "preview_max_x": "2048", "preview_max_y": "2048", "jpeg_quality": "60" }

External storages: yes

External storage configuration

Encryption: no

User-backends:

OC\User\Database

[cmasterdelphi]

I have the same issue. Reason, I do not want to have the user active nor do I want the user to be deleted. But also having "Fatal Errors" every few seconds in my logging is also not really an option, because I wouldn't see any "real" errors!

There shouldn't be errors for deactivated users

[szaimen]

Is this Issue still valid in NC21.0.3? If not, please close this issue. Thanks! :)

[ghost]

This issue has been automatically marked as stale because it has not had recent activity and seems to be missing some essential information. It will be closed if no further activity occurs. Thank you for your contributions.

[patricksebastien]

Still present in 21.0.4 :(

Fatal | webdav | Sabre\DAV\Exception\ServiceUnavailable: OC\User\LoginException: User disabled

[patricksebastien]

In the meantime (reported 1 year ago), I would like to contact all the users that are still trying to connect via their desktop client, how to do that, the login information is hidden from me:

.../nextcloud/app/lib/private/User/Session.php - line 665:
OC\User\Session->completeLogin("*** sensiti ... *")

[patricksebastien]

Still present in 22.2.3 Is there any plan to tackle this for Nextcloud 23?

[patricksebastien]

Still present in 23.0.4 Is there any plan to tackle this for Nextcloud 24?

[RuudschMaHinda]

Still present in 24.0.2 Is there any plan to tackle this for Nextcloud 24.0.3? Got to check the access log, and compare usernames sent by the clients with the deactivated list. Can become tedious when lots of people get switched around.

[meise]

Still present in 24.0.6…

[szaimen]

Hi, please update to 24.0.9 or better 25.0.3 and report back if it fixes the issue. Thank you!

My goal is to add a label like e.g. 25-feedback to this ticket of an up-to-date major Nextcloud version where the bug could be reproduced. However this is not going to work without your help. So thanks for all your effort!

If you don't manage to reproduce the issue in time and the issue gets closed but you can reproduce the issue afterwards, feel free to create a new bug report with up-to-date information by following this link: https://github.com/nextcloud/server/issues/new?assignees=&labels=bug%2C0.+Needs+triage&template=BUG_REPORT.yml&title=%5BBug%5D%3A+

[angawest]

Still present in 25.0.3...

[patricksebastien]

And 26.0.1... it doesn't make sense to throw a fatal error for this.

[sfriedri-tinkertoys]

Still present in 27.1.2...

[SnejPro]

I think this is not a small issue. Error logs should tell me errors I need to fix. But when error logs are spammed with debug messages (nothing else is the message that a disabled user tries to log in), the logs cannot fulfill their purpose.

[ameed-aabidi]

Facing the same issue since NC 26. A user was disabled but had webdav/caldav services active in his device (maybe calendar and a number of other services), and every time they client attempts to authenticate, it logs this "User disabled" error. It's annoying and since we do not have any means to contact the user any more, it's just a log error that we have to ignore.

Current setup: NC 28.0.1 PHP 8.2 FPM - Apache - Nginx (proxy)

[KornKalle]

Still present in 28.0.5, got even worse as the admin page is displaying "XXX errors since XXX", makes this new message kind of unusable

[joshtrichards]

Looked into this a bit. Don't have a full solution to propose, but adding some notes for myself or someone else to pick up another time.

There are two entries generated in the logs. The LoginException itself is generated here:

https://github.com/nextcloud/server/blob/bae9e2e6e1ded38972916de0a8bf49e5ef1d2f71/lib/private/User/Session.php#L366-L372

The log entry for it occurs due to line 144 here:

https://github.com/nextcloud/server/blob/bae9e2e6e1ded38972916de0a8bf49e5ef1d2f71/apps/dav/lib/Connector/Sabre/Auth.php#L141-L146

The ServiceUnavailable exception is then thrown and not captured so it too gets logged.

I don't think we can just catch LoginException because it's used in a few places.

I'm thinking maybe we could create a LoginDisabledException to distinguish it from the other places. That could then be caught and handled as deemed appropriate rather than:

• getting logged twice
• getting logged at ERROR level (INFO maybe)

Still not a complete solution though because we need to work out what to do about the ServiceUnavailable. That's actually used AFAIK to convey temporary scenarios to clients (so that they don't give up permanently/etc). So that piece needs to be looked at closer to make sure we don't break anything with the clients (web, mobile, desktop).

Didn't get to that this evening. If someone else runs across this and feels like digging in a bit, feel free.

Historical ref: 8eda6617618e0a1f650afc4e6766e799b4e62b82

EDIT: Since disabled users are a temporary state, we should be handling them certainly as well as we do outright login failures (which we handle just fine). So another path might be here.

[joshtrichards]

In the meantime (reported 1 year ago), I would like to contact all the users that are still trying to connect via their desktop client, how to do that, the login information is hidden from me

@patricksebastien The user is embedded in the URL of the log entry (though maybe there are some scenarios where it wouldn't be - not sure):

"PROPFIND","url":"/remote.php/dav/principals/users/ncuser/

[dafi87]

This is still an issue in 29.0.3