Web login fails silently with weird log file entry


#1

Steps to reproduce

  1. Install owncloud
  2. Attempt admin login

Expected behaviour

Proceed with login.

Actual behaviour

The login page just reloads without any visible error messages.

Server configuration

Operating system:
FreeBSD 11.2 amd64

Web server:
apache 2.4

Database:
mysql 5.7

PHP version:
7.2

ownCloud version: (see ownCloud admin page)
10.0.10

Updated from an older ownCloud or fresh install:
fresh install

Where did you install ownCloud from:
downloaded archive from official website

Signing status (ownCloud 9.0 and above):
can’t login to get this

The content of config/config.php:

{
    "system": {
        "instanceid": "ockvws991n8p",
        "passwordsalt": "***REMOVED SENSITIVE VALUE***",
        "secret": "***REMOVED SENSITIVE VALUE***",
        "trusted_domains": [
            "www.mydomain.com"
        ],
        "datadirectory": "\/www\/owncloud\/data",
        "overwrite.cli.url": "http:\/\/www.mydomain.com\/occ",
        "dbtype": "mysql",
        "version": "10.0.10.4",
        "dbname": "owncloud",
        "dbhost": "localhost",
        "dbtableprefix": "oc_",
        "mysql.utf8mb4": true,
        "dbuser": "***REMOVED SENSITIVE VALUE***",
        "dbpassword": "***REMOVED SENSITIVE VALUE***",
        "logtimezone": "UTC",
        "installed": true
    },
    "apps": {
        "backgroundjob": {
            "lastjob": "8"
        },
        "comments": {
            "enabled": "yes",
            "installed_version": "0.3.0",
            "types": "logging,dav"
        },
        "configreport": {
            "enabled": "yes",
            "installed_version": "0.1.1",
            "types": "filesystem"
        },
        "core": {
            "first_install_version": "10.0.10.4",
            "installedat": "1541838707.2229",
            "lastcron": "1541839833",
            "lastupdatedat": "1541838707.2243",
            "oc.integritycheck.checker": "[]",
            "public_files": "files_sharing\/public.php",
            "public_webdav": "dav\/appinfo\/v1\/publicwebdav.php"
        },
        "dav": {
            "enabled": "yes",
            "installed_version": "0.4.0",
            "types": "filesystem"
        },
        "federatedfilesharing": {
            "enabled": "yes",
            "installed_version": "0.3.1",
            "types": "filesystem"
        },
        "federation": {
            "enabled": "yes",
            "installed_version": "0.1.0",
            "types": "authentication"
        },
        "files": {
            "cronjob_scan_files": "500",
            "enabled": "yes",
            "installed_version": "1.5.1",
            "types": "filesystem"
        },
        "files_external": {
            "enabled": "yes",
            "installed_version": "0.7.1",
            "ocsid": "166048",
            "types": "filesystem"
        },
        "files_sharing": {
            "enabled": "no",
            "installed_version": "0.11.0",
            "types": "filesystem"
        },
        "files_trashbin": {
            "enabled": "yes",
            "installed_version": "0.9.1",
            "types": "filesystem"
        },
        "files_versions": {
            "enabled": "yes",
            "installed_version": "1.3.0",
            "types": "filesystem"
        },
        "files_videoplayer": {
            "enabled": "yes",
            "installed_version": "0.9.8",
            "types": ""
        },
        "firstrunwizard": {
            "enabled": "yes",
            "installed_version": "1.1",
            "ocsid": "166055",
            "types": ""
        },
        "market": {
            "enabled": "yes",
            "installed_version": "0.2.5",
            "types": ""
        },
        "notifications": {
            "enabled": "yes",
            "installed_version": "0.3.5",
            "types": "logging"
        },
        "provisioning_api": {
            "enabled": "yes",
            "installed_version": "0.5.0",
            "types": "prevent_group_restriction"
        },
        "systemtags": {
            "enabled": "yes",
            "installed_version": "0.3.0",
            "types": "logging"
        },
        "updatenotification": {
            "enabled": "yes",
            "installed_version": "0.2.1",
            "types": ""
        }
    }
}

List of activated apps:

Enabled:
  - comments: 0.3.0
  - configreport: 0.1.1
  - dav: 0.4.0
  - federatedfilesharing: 0.3.1
  - federation: 0.1.0
  - files: 1.5.1
  - files_external: 0.7.1
  - files_trashbin: 0.9.1
  - files_versions: 1.3.0
  - files_videoplayer: 0.9.8
  - firstrunwizard: 1.1
  - market: 0.2.5
  - notifications: 0.3.5
  - provisioning_api: 0.5.0
  - systemtags: 0.3.0
  - updatenotification: 0.2.1
Disabled:
  - encryption
  - external
  - files_sharing
  - user_external

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

Firefox, Opera, Internet Explorer

Operating system:
Windows 8.1

Logs

Web server error log

Nothing relevant

ownCloud log (data/owncloud.log)

Log entry when trying to login with valid password (actual username is ‘admin’)

{"reqId":"cyLUDinu5igPXmn12ezp","level":2,"time":"2018-11-10T09:38:28+00:00","remoteAddr":"xx.xx.xx.xx","user":"admin","app":"core","method":"GET","url":"\/occ\/index.php\/apps\/files\/","message":"Login failed: 'username' (Remote IP: 'xx.xx.xx.xx')"}
{"reqId":"cyLUDinu5igPXmn12ezp","level":2,"time":"2018-11-10T09:38:28+00:00","remoteAddr":"xx.xx.xx.xx","user":"--","app":"core","method":"GET","url":"\/occ\/index.php\/apps\/files\/","message":"Login failed: 'username' (Remote IP: 'xx.xx.xx.xx')"}

Log entry when trying to login with invalid password:

{"reqId":"wpzKZFYVGbEtE7EG9fll","level":2,"time":"2018-11-10T09:43:22+00:00","remoteAddr":"xx.xx.xx.xx","user":"--","app":"core","method":"POST","url":"\/occ\/index.php\/login?redirect_url=%252Focc%252Findex.php%252Fapps%252Ffiles%252F","message":"Login failed: 'admin' (Remote IP: 'xx.xx.xx.xx')"}

Browser log

Javascript console shows:

JQMIGRATE: Migrate is installed, version 1.4.0 jquery-migrate.min.js:2:542
Deprecation warning: tipsy is deprecated. Use tooltip instead. js.js:2296:2
Password fields present on an insecure (http://) page. This is a security risk that allows user login credentials to be stolen.[Learn More] login

Comments

I really have no idea what to try. I’ve seen similar threads, but the proposed workaround (disabling files_sharing app) doesn’t seem to change anything.

What I find curious is that the log says “Login failed: ‘username’”, even though the user I am trying to log in with is ‘admin’, but that ONLY happen if the provided password is correct. When the password is incorrect the log correctly states “Login failed: ‘admin’”. I don’t know what the significance of this observation is, but still, it feels weird.


#2

What I find really strange:

The two log messages don’t refer to a login activity, rather than a file access. There are no log entries on a web-login with loglevel 2.

You could give more info, what exactly you did.


#3

Thank you for your answer!

Here is the log with loglevel 0

{"reqId":"p0n4L39J867623P0Nr03","level":0,"time":"2018-11-11T08:53:38+00:00","remoteAddr":"xx.xx.xx.xx","user":"--","app":"OC\\User\\Session::login","method":"POST","url":"\/occ\/index.php\/login?redirect_url=%252Focc%252Findex.php%252Fapps%252Ffiles%252F","message":"regenerating session id for uid admin, password set"}
{"reqId":"p0n4L39J867623P0Nr03","level":0,"time":"2018-11-11T08:53:38+00:00","remoteAddr":"xx.xx.xx.xx","user":"--","app":"OC\\Authentication\\Token\\DefaultTokenProvider::getToken","method":"POST","url":"\/occ\/index.php\/login?redirect_url=%252Focc%252Findex.php%252Fapps%252Ffiles%252F","message":"token cea6ab62f03a80f4f8b815f2d85b8b548d64ea5c3cc6f3458a7469d1a37d14537b5d4efcd96f494ca88d43148d44d8763490ff3762908d5a9a00438122041255 does not exist"}
{"reqId":"p0n4L39J867623P0Nr03","level":0,"time":"2018-11-11T08:53:38+00:00","remoteAddr":"xx.xx.xx.xx","user":"--","app":"OC\\User\\Session::validateToken","method":"POST","url":"\/occ\/index.php\/login?redirect_url=%252Focc%252Findex.php%252Fapps%252Ffiles%252F","message":"token cea6ab62f03a80f4f8b815f2d85b8b548d64ea5c3cc6f3458a7469d1a37d14537b5d4efcd96f494ca88d43148d44d8763490ff3762908d5a9a00438122041255, not found"}
{"reqId":"p0n4L39J867623P0Nr03","level":0,"time":"2018-11-11T08:53:38+00:00","remoteAddr":"xx.xx.xx.xx","user":"admin","app":"OC\\Authentication\\Token\\DefaultTokenProvider::getToken","method":"POST","url":"\/occ\/index.php\/login?redirect_url=%252Focc%252Findex.php%252Fapps%252Ffiles%252F","message":"token cea6ab62f03a80f4f8b815f2d85b8b548d64ea5c3cc6f3458a7469d1a37d14537b5d4efcd96f494ca88d43148d44d8763490ff3762908d5a9a00438122041255 does not exist"}
{"reqId":"p0n4L39J867623P0Nr03","level":0,"time":"2018-11-11T08:53:38+00:00","remoteAddr":"xx.xx.xx.xx","user":"admin","app":"OC\\Authentication\\Token\\DefaultTokenProvider::generateToken","method":"POST","url":"\/occ\/index.php\/login?redirect_url=%252Focc%252Findex.php%252Fapps%252Ffiles%252F","message":"generating token 64dd9ce4e1dd1e68fc5a86d6c529961908c01dfddbde2a52590f560ffcd8903f32e854cb96a3ee108d85f4b266509233fead214c50d8e76a311bb230cc0a5753, uid admin, loginName admin, pwd set, name Mozilla\/5.0 (Windows NT 6.3; Win64; x64; rv:63.0) Gecko\/20100101 Firefox\/63.0, type temporary"}
{"reqId":"vTHjccYGTHiB43U5TsLY","level":0,"time":"2018-11-11T08:53:38+00:00","remoteAddr":"xx.xx.xx.xx","user":"admin","app":"OC\\User\\Session::validateToken","method":"GET","url":"\/occ\/index.php\/apps\/files\/","message":"token 64dd9ce4e1dd1e68fc5a86d6c529961908c01dfddbde2a52590f560ffcd8903f32e854cb96a3ee108d85f4b266509233fead214c50d8e76a311bb230cc0a5753 with token id 3 found, validating"}
{"reqId":"vTHjccYGTHiB43U5TsLY","level":0,"time":"2018-11-11T08:53:38+00:00","remoteAddr":"xx.xx.xx.xx","user":"admin","app":"OC\\Authentication\\Token\\DefaultTokenProvider::getToken","method":"GET","url":"\/occ\/index.php\/apps\/files\/","message":"token e8d1fdba6f6912420b249216e506789f3c6217c7e2e8f365e644d1dd498a11038bd1a44c3a8e85a788ee630470f703d8e5989ba2c0c121f1191db7649989cd49 does not exist"}
{"reqId":"vTHjccYGTHiB43U5TsLY","level":2,"time":"2018-11-11T08:53:38+00:00","remoteAddr":"xx.xx.xx.xx","user":"admin","app":"core","method":"GET","url":"\/occ\/index.php\/apps\/files\/","message":"Login failed: 'username' (Remote IP: 'xx.xx.xx.xx')"}
{"reqId":"vTHjccYGTHiB43U5TsLY","level":0,"time":"2018-11-11T08:53:38+00:00","remoteAddr":"xx.xx.xx.xx","user":"admin","app":"OC\\User\\BasicAuthModule::auth","method":"GET","url":"\/occ\/index.php\/apps\/files\/","message":"Invalid password for username username, trying as email."}
{"reqId":"vTHjccYGTHiB43U5TsLY","level":0,"time":"2018-11-11T08:53:38+00:00","remoteAddr":"xx.xx.xx.xx","user":"admin","app":"OC\\Authentication\\Token\\DefaultTokenProvider::invalidateToken","method":"GET","url":"\/occ\/index.php\/apps\/files\/","message":"invalidating token 64dd9ce4e1dd1e68fc5a86d6c529961908c01dfddbde2a52590f560ffcd8903f32e854cb96a3ee108d85f4b266509233fead214c50d8e76a311bb230cc0a5753"}
{"reqId":"vTHjccYGTHiB43U5TsLY","level":0,"time":"2018-11-11T08:53:38+00:00","remoteAddr":"xx.xx.xx.xx","user":"--","app":"OC\\Authentication\\Token\\DefaultTokenProvider::getToken","method":"GET","url":"\/occ\/index.php\/apps\/files\/","message":"token 64dd9ce4e1dd1e68fc5a86d6c529961908c01dfddbde2a52590f560ffcd8903f32e854cb96a3ee108d85f4b266509233fead214c50d8e76a311bb230cc0a5753 does not exist"}
{"reqId":"vTHjccYGTHiB43U5TsLY","level":0,"time":"2018-11-11T08:53:38+00:00","remoteAddr":"xx.xx.xx.xx","user":"--","app":"OC\\Authentication\\Token\\DefaultTokenProvider::getToken","method":"GET","url":"\/occ\/index.php\/apps\/files\/","message":"token e8d1fdba6f6912420b249216e506789f3c6217c7e2e8f365e644d1dd498a11038bd1a44c3a8e85a788ee630470f703d8e5989ba2c0c121f1191db7649989cd49 does not exist"}
{"reqId":"vTHjccYGTHiB43U5TsLY","level":0,"time":"2018-11-11T08:53:38+00:00","remoteAddr":"xx.xx.xx.xx","user":"--","app":"OC\\User\\Session::login","method":"GET","url":"\/occ\/index.php\/apps\/files\/","message":"regenerating session id for uid username, password set"}
{"reqId":"vTHjccYGTHiB43U5TsLY","level":0,"time":"2018-11-11T08:53:38+00:00","remoteAddr":"xx.xx.xx.xx","user":"--","app":"OC\\Authentication\\Token\\DefaultTokenProvider::getToken","method":"GET","url":"\/occ\/index.php\/apps\/files\/","message":"token e8d1fdba6f6912420b249216e506789f3c6217c7e2e8f365e644d1dd498a11038bd1a44c3a8e85a788ee630470f703d8e5989ba2c0c121f1191db7649989cd49 does not exist"}
{"reqId":"vTHjccYGTHiB43U5TsLY","level":0,"time":"2018-11-11T08:53:38+00:00","remoteAddr":"xx.xx.xx.xx","user":"--","app":"OC\\User\\Session::validateToken","method":"GET","url":"\/occ\/index.php\/apps\/files\/","message":"token e8d1fdba6f6912420b249216e506789f3c6217c7e2e8f365e644d1dd498a11038bd1a44c3a8e85a788ee630470f703d8e5989ba2c0c121f1191db7649989cd49, not found"}
{"reqId":"vTHjccYGTHiB43U5TsLY","level":2,"time":"2018-11-11T08:53:38+00:00","remoteAddr":"xx.xx.xx.xx","user":"--","app":"core","method":"GET","url":"\/occ\/index.php\/apps\/files\/","message":"Login failed: 'username' (Remote IP: 'xx.xx.xx.xx')"}
{"reqId":"vTHjccYGTHiB43U5TsLY","level":0,"time":"2018-11-11T08:53:38+00:00","remoteAddr":"xx.xx.xx.xx","user":"--","app":"no app in context","method":"GET","url":"\/occ\/index.php\/apps\/files\/","message":"Current user is not logged in"}
{"reqId":"u2Ab1IznHM2xbhx26LTP","level":0,"time":"2018-11-11T08:53:39+00:00","remoteAddr":"xx.xx.xx.xx","user":"--","app":"cron","method":"GET","url":"\/occ\/cron.php","message":"Started background job of class : OCA\\Federation\\SyncJob with arguments : "}
{"reqId":"u2Ab1IznHM2xbhx26LTP","level":0,"time":"2018-11-11T08:53:39+00:00","remoteAddr":"xx.xx.xx.xx","user":"--","app":"cron","method":"GET","url":"\/occ\/cron.php","message":"Finished background job, the job took : 0 seconds, this job is an instance of class : OCA\\Federation\\SyncJob with arguments : "}

I’d gladly give more info, but can’t think of anything relevant. My installation process was something like

  1. Extracting the the tarball it in directory registered in the apache configuration as alias
  2. Creating mysql database + user
  3. Opening index in browser, populating the forms with mysql details and submitting it
  4. Reseting admin password using in login shell (via occ tool)
  5. That’s pretty much it. I was playing around with disabling apps trying to isolate the problem, but never really made any difference.

#4

I assume, this redirect_url to the files app is bogus. Compared to my system.
Check your apache and or proxy config.


#5

Okay, this is embarrassing.

It was my fault after all. When I was setting up the directory details in apache config I used AuthType Basic. After trying to login and failed, I read the documentation more carefully and noticed that AuthType should not be used. I turned it off, but obviously my browser didn’t bother to stop sending the saved credentials and the login kept failing.

Clearing the saved credentials didn’t really help either, but using a new private window did it.

Long story short: Do not use AuthType Basic for owncloud directory.