search

owncloud-archive / apps

Repo for ownCloud apps. Code here is work in progress and not intended for endusers
373 stars 337 forks source link

IMAP Authentication randomly stops and starts working. #2086

Open tgrondin opened 9 years ago

tgrondin commented 9 years ago

Issue: External authentication using IMAP randomly stops working. When this happens, only database users such as the default admin user are able to login. IMAP authentication starts working again at random and then breaks again, seemingly at random.

I can replicate the issue on versions 8.04, 8.0.5, and 8.1.

Steps to reproduce

  1. Enable user_external
  2. Configure IMAP authentication in config/config.php
  3. Random login attempts fail and the system falls back to database authentication.

    Expected behavior

The login attempt should verify against the IMAP server and grant access every time.

Actual behavior

IMAP authentication is not tried and a 401 error code is returned to the clients. If attempting to login via the web interface, OwnCloud displays the reset password option.

It does not appear to be client specific. I have tested with Thunderbird CalDAV, Gnome's built in OwnCloud integration, the official OwnCloud sync app for windows, and Davdroid for Android.

Server configuration

Operating system: FreeBSD 10.1

Web server: nginx version: nginx/1.8.0 built with OpenSSL 1.0.2d 9 Jul 2015 TLS SNI support enabled

Database: Mariadb server v10.0.17

PHP version: PHP 5.6.11 (cli) (built: Jul 13 2015

ownCloud version: 8.1.0 (production)

Updated from an older ownCloud or fresh install: Initial install was 8.0.3. Upgraded to 8.04, and 8.05 and then 8.1. The IMAP authentication issue started with 8.04.

List of activated apps: % php occ app:list Enabled:

The content of config/config.php: I removed the database and mail lines for brevity and replaced identifying information. $CONFIG = array ( 'instanceid' => 'removed', 'passwordsalt' => 'removed', 'secret' => 'removed', 'trusted_domains' => array ( 0 => 'cloud.removed.com', ), 'datadirectory' => '/private_html/data', 'dbtype' => 'mysql', 'version' => '8.1.0.8', 'installed' => true, 'enable_previews' => 'true', 'theme' => 'custom', 'knowledgebaseenabled' => false, 'maintenance' => false, 'loglevel' => 0, 'forcessl' => false, 'forceSSLforSubdomains' => false, 'mail_smtpsecure' => 'tls', 'appstoreenabled' => false, 'user_backends' => array ( 0 => array ( 'class' => 'OC_User_IMAP', 'arguments' => array ( 0 => '{imap.removed.com:143/imap/tls}INBOX', ), ), ), );

Are you using external storage?: Nothing configured by default. Authenticated users can set up their own external storage such as FTP, SFTP.

Are you using encryption: yes/no No

Are you using an external user-backend, if yes which one: LDAP/ActiveDirectory/Webdav/... Yes. User External with IMAP.

Client configuration

Browser: Firefox, Chrome, Epiphany,

Operating system: Fedora 22

Logs

Web server error log 2015/07/21 14:10:29 [error] 40893#0: 3084445 access forbidden by rule, client: , server: cloud.removed.com, request: "GET /data/htaccesstest.txt HTTP/1.0", host: "cloud.removed" 2015/07/21 14:37:41 [error] 40904#0: 3091696 access forbidden by rule, client: , server: cloud.removed.com, request: "GET /data/htaccesstest.txt HTTP/1.0", host: "cloud.removed"

Web server access log cloud.removed - - [21/Jul/2015:14:49:13 +0000] "GET /remote.php/webdav/ HTTP/1.0" 401 242 "-" "-" ""0.130 MISS cloud.removed - - [21/Jul/2015:14:49:13 +0000] "GET /remote.php/webdav/ HTTP/1.0" 401 242 "-" "-" ""0.130 MISS cloud.removed - user@example.com [21/Jul/2015:14:49:13 +0000] "GET /remote.php/webdav/ HTTP/1.0" 401 235 "-" "-" ""0.151 MISS cloud.removed - user@example2.com [21/Jul/2015:14:49:13 +0000] "GET /remote.php/webdav/ HTTP/1.0" 401 235 "-" "-" ""0.148 MISS

ownCloud log (data/owncloud.log) {"reqId":"MF2rLIjRwslfrbbarsnk","remoteAddr":"","app":"core","message":"Login failed: 'user@example.com' (Remote IP: ')","level":2,"time":"2015-07-21T14:50:58+00:00","method":"GET","url":"\/remote.php\/webdav\/"} {"reqId":"MF2rLIjRwslfrbbarsnk","remoteAddr":"","app":"webdav","message":"Exception: {\"Message\":\"HTTP\/1.1 401 Username or password does not match\",\"Code\":0,\"Trace\":\"#0 \/public_html\/lib\/private\/connector\/sabre\/auth.php(149):

Note: Once login starts working again, I see the following.

{"reqId":"aikQmOUHy82BfpUP546w","remoteAddr":"","app":"core","message":"User backend OC_User_IMAP already initialized.","level":0,"time":"2015-07-21T14:53:54+00:00","method":"POST","url":"\/index.php"}

Note: This is what I see in the dovecot server log when authentication fails. While there is a connection, no authentication attempt is made.

IMAP Server Log: Jul 21 15:30:32 mail dovecot: imap-login: Disconnected (no auth attempts in 0 secs): user=<>, rip=, lip=, TLS handshaking: Disconnected, session=<nEC/VWQbxQDYESpI>

Other Notes: I can run any tests needed or setup a duplicate development environment if required.

tgrondin commented 9 years ago

Here are some additional entries from the data/owncloud.log file. This is what I see when the above issue happens and I try to log into the web interface.

{"reqId":"5hqN5IlzCLvb0dDNqQ5X","remoteAddr":"","app":"core","message":"User backend OC_User_IMAP already initialized.","level":0,"time":"2015-07-23T18:30:34+00:00","method":"POST","url":"\/index.php"} {"reqId":"5hqN5IlzCLvb0dDNqQ5X","remoteAddr":"","app":"core","message":"Login failed: 'user@example.com' (Remote IP: ')","level":2,"time":"2015-07-23T18:30:34+00:00","method":"POST","url":"\/index.php"} {"reqId":"Ug6+WPwcZf7i+2jsSsbm","remoteAddr":"","app":"core","message":"User backend OC_User_IMAP already initialized.","level":0,"time":"2015-07-23T18:30:36+00:00","method":"POST","url":"\/index.php"} {"reqId":"Ug6+WPwcZf7i+2jsSsbm","remoteAddr":"","app":"core","message":"Login failed: 'user@example.com' (Remote IP: ')","level":2,"time":"2015-07-23T18:30:36+00:00","method":"POST","url":"\/index.php"} {"reqId":"KJY1tM9jRjxdBKjqexlG","remoteAddr":"","app":"core","message":"User backend OC_User_IMAP already initialized.","level":0,"time":"2015-07-23T18:31:25+00:00","method":"POST","url":"\/index.php"} {"reqId":"KJY1tM9jRjxdBKjqexlG","remoteAddr":"","app":"core","message":"Login failed: 'user@example.com' (Remote IP: ')","level":2,"time":"2015-07-23T18:31:25+00:00","method":"POST","url":"\/index.php"}

As above, there is a connection made to the IMAP server, but no authentication attempts are made.

mmccarn commented 9 years ago

IMAP auth is working reliably for me.

You have these apps installed that I do not:

Here is my app:list for comparison:

$ sudo -u www-data php occ app:list
Enabled:
 - activity: 2.0.1
 - external: 1.2
 - files: 1.1.10
 - files_external: 0.2.3
 - files_locking: 
 - files_mv: 0.8.1a
 - files_pdfviewer: 0.7
 - files_sharing: 0.6.2
 - files_texteditor: 0.4
 - files_trashbin: 0.6.3
 - files_versions: 1.0.6
 - files_videoviewer: 0.1.3
 - firstrunwizard: 1.1
 - provisioning_api: 0.2
 - templateeditor: 0.1
 - user_external: 0.4
Disabled:
 - documents
 - encryption
 - gallery
 - user_ldap
 - user_webdavauth
tgrondin commented 9 years ago

Hello,

The issue appears to be triggered by using a dynamic PHP-FPM configuration. It does not occur when using a static configuration. I have included both types of configuration below for reference.

PHP-FPM DYNAMIC pm = dynamic pm.max_children = 10 pm.start_servers = 2 pm.min_spare_servers = 2 pm.max_spare_servers = 4 pm.max_requests = 15000 pm.process_idle_timeout = 10s request_terminate_timeout = 240s

PHP-FPM STATIC pm = static pm.max_children = 10 pm.process_idle_timeout = 10s request_terminate_timeout = 240s

It's almost like there is some type of disconnect that happens between session handling and authentication. I suspect it has to do with the cycling process that happens after pm.max_requests expires.

The rest of OwnCloud and every app I have tried works fine with a dynamic configuration. It only seems to affect user_external.

I can setup testing environments and run any tests or patches. I'd really like to see this work with a dynamic configuration instead of static.