Client: 2.4.0: Fails to connect with HTTP2

Created on 5 Jan 2018  路  34Comments  路  Source: owncloud/client

On Debian user complains, that the new occ 2.4.0 do not connect anymore to Nextcloud 12. Worked with 2.3.3 perfectly. Here the bts/886395:

When I use the logging window here are some of the network error I
have:

QNetworkReply::NetworkError(ServiceUnavailableError) "Error transferring https://xxxx/remote.php/dav/files/yyyy/ - server replied: " QVariant(int, 503)

The 503 HTTP Error seems strange as I can access the web interface of
nextcloud through firefox. When I try to reach the aforementioned URL
with firefox I've got a message telling me that I reached a WebDAV
interface which indicates that everything is normal.

I also have this error:

QNetworkReply::NetworkError(ServiceUnavailableError) "Error transferring https://xxxx/status.php - server replied: " QVariant(int, 503)

But when I use curl to fetch this page I receive the expected JSON:

 {"installed":true,
  "maintenance":false,
  "needsDbUpgrade":false,
  "version":"12.0.4.3",
  "versionstring":"12.0.4",
  "edition":"",
  "productname":"Nextcloud"}

Also there's a thread in the NextCloud forum: help.nextcloud.com/owncloud-desktop-client-2-4-0-with-nextcloud-12

Server Involved bug
Source
picture hefee

All 34 comments

If the client receives a 503 reply from the server it will assume it's temporarily unavailable and try again later.

When a browser or curl were used to access the same url they sent a GET request. That doesn't tell us about what would happen for a PROPFIND that the client probably sent.

A client log file might be helpful for investigating this issue (https://doc.owncloud.org/desktop/2.3/troubleshooting.html#saving-files-directly).

ckamm picture ckamm on 5 Jan 2018

I suppose the server log might contain information about why there is an error.

ogoffart picture ogoffart on 5 Jan 2018

@ckamm - here is the requested client log:

01-05 21:05:43:905 [ info sync.csync.updater ]: file: xxxxxx , instruction: INSTRUCTION_NONE <<=
01-05 21:05:43:905 [ info sync.csync ]: Memory: 1048648K total size, 127164K resident, 70300K shared
01-05 21:06:01:449 [ info sync.accessmanager ]: 6 "PROPFIND" "https://sub.domain.tld/remote.php/dav/files/ncuser/" has X-Request-ID "53b21565-ec8e-4309-bc9b-ca55fe3e81c0"
01-05 21:06:01:451 [ info sync.networkjob ]:    OCC::LsColJob created for "https://sub.domain.tld" + "" "OCC::DiscoverySingleDirectoryJob"
01-05 21:06:01:478 [ info sync.accessmanager ]: 6 "PROPFIND" "https://sub.domain.tld/remote.php/dav/files/ncuser/" has X-Request-ID "add3635c-04d3-409f-bb8c-61b38fa324eb"
01-05 21:06:01:480 [ info sync.networkjob ]:    OCC::PropfindJob created for "https://sub.domain.tld" + "/" "OCC::QuotaInfo"
01-05 21:06:01:481 [ info sync.accessmanager ]: 6 "PROPFIND" "https://sub.domain.tld/remote.php/dav/files/ncuser/" has X-Request-ID "fdcd54c0-d04d-4813-bb94-e7436172ce71"
01-05 21:06:01:482 [ info sync.networkjob ]:    OCC::PropfindJob created for "https://sub.domain.tld" + "/" "OCC::ConnectionValidator"
01-05 21:06:01:483 [ info gui.folder.manager ]: Scheduling folder "1" , the last 1 syncs failed , anotherSyncNeeded 0 , last status: "SyncPrepare" , time since last sync: 32151
01-05 21:06:01:485 [ info gui.folder.manager ]: Schedule folder  "1"  to sync!
01-05 21:06:01:486 [ info gui.application ]:    Sync state changed for folder  "https://sub.domain.tld/remote.php/dav/files/ncuser/" :  "Not yet Started"
01-05 21:06:01:488 [ info sync.accessmanager ]: 2 "" "https://sub.domain.tld/ocs/v2.php/apps/notifications/api/v1/notifications?format=json" has X-Request-ID "03991aa8-92d0-4acb-b055-e85437bec527"
01-05 21:06:01:489 [ info sync.networkjob ]:    OCC::JsonApiJob created for "https://sub.domain.tld" + "ocs/v2.php/apps/notifications/api/v1/notifications" "OCC::ServerNotificationHandler"
01-05 21:06:01:676 [ warning sync.networkjob ]: QNetworkReply::NetworkError(ServiceUnavailableError) "Error transferring https://sub.domain.tld/remote.php/dav/files/ncuser/ - server replied: " QVariant(int, 503)
01-05 21:06:01:678 [ info sync.networkjob.propfind ]:   PROPFIND of QUrl("https://sub.domain.tld/remote.php/dav/files/ncuser/") FINISHED WITH STATUS QNetworkReply::NetworkError(ServiceUnavailableError) "Error transferring https://sub.domain.tld/remote.php/dav/files/ncuser/ - server replied: "
01-05 21:06:01:679 [ warning sync.networkjob.propfind ]:    *not* successful, http result code is 503 ""
01-05 21:06:01:680 [ warning sync.networkjob ]: QNetworkReply::NetworkError(ServiceUnavailableError) "Error transferring https://sub.domain.tld/remote.php/dav/files/ncuser/ - server replied: " QVariant(int, 503)
01-05 21:06:01:681 [ info sync.networkjob.propfind ]:   PROPFIND of QUrl("https://sub.domain.tld/remote.php/dav/files/ncuser/") FINISHED WITH STATUS QNetworkReply::NetworkError(ServiceUnavailableError) "Error transferring https://sub.domain.tld/remote.php/dav/files/ncuser/ - server replied: "
01-05 21:06:01:682 [ warning sync.networkjob.propfind ]:    *not* successful, http result code is 503 ""
01-05 21:06:01:684 [ info gui.account.state ]:  AccountState connection status change:  "Connected" -> "Service unavailable"
01-05 21:06:01:685 [ info gui.account.state ]:  AccountState state change:  "Verbunden" -> "Dienst nicht verf眉gbar"
01-05 21:06:01:693 [ info gui.folder.manager ]: Account "[email protected]" disconnected or paused, terminating or descheduling sync folders
01-05 21:06:01:694 [ info gui.folder ]: folder  "1"  Terminating!
01-05 21:06:01:695 [ warning sync.networkjob ]: QNetworkReply::NetworkError(OperationCanceledError) "Operation abgebrochen" QVariant(Invalid)
01-05 21:06:01:696 [ info sync.networkjob.lscol ]:  LSCOL of QUrl("https://sub.domain.tld/remote.php/dav/files/ncuser/") FINISHED WITH STATUS QNetworkReply::NetworkError(OperationCanceledError) "Operation abgebrochen"
01-05 21:06:01:697 [ warning sync.discovery ]:  LSCOL job error "Operation abgebrochen" 0 QNetworkReply::NetworkError(OperationCanceledError)
01-05 21:06:01:702 [ info sync.connectionvalidator ]:   No system proxy set by OS
01-05 21:06:01:703 [ info sync.accessmanager ]: 2 "" "https://sub.domain.tld/status.php" has X-Request-ID "20e48d6c-4c8e-4c21-9582-ee47cf4d83a7"
01-05 21:06:01:705 [ info sync.networkjob ]:    OCC::CheckServerJob created for "https://sub.domain.tld" + "status.php" "OCC::ConnectionValidator"
01-05 21:06:01:707 [ warning sync.engine ]: ERROR during  csync_update :  "Abbruch durch den Benutzer Abbruch durch den Benutzer"
01-05 21:06:01:708 [ info sync.engine ]:    Update phase was aborted by user!
01-05 21:06:01:719 [ info sync.database ]:  Closing DB "/home/ncuser/ownCloud/._sync_08a0c2b44f44.db"
01-05 21:06:01:720 [ info sync.engine ]:    CSync run took  18212 ms
01-05 21:06:01:734 [ info gui.folder ]: Client version 2.4.0  Qt 5.9.2  SSL  OpenSSL 1.0.2n  7 Dec 2017
01-05 21:06:01:736 [ info gui.folder ]: SyncEngine finished without problem.
01-05 21:06:01:737 [ info gui.folder ]: Folder sync result:  4
01-05 21:06:01:738 [ info gui.application ]:    Sync state changed for folder  "https://sub.domain.tld/remote.php/dav/files/ncuser/" :  "Success"
01-05 21:06:01:931 [ warning sync.networkjob ]: QNetworkReply::NetworkError(ServiceUnavailableError) "Error transferring https://sub.domain.tld/status.php - server replied: " QVariant(int, 503)
01-05 21:06:01:931 [ warning sync.networkjob.checkserver ]: error: status.php replied  503 ""
01-05 21:06:01:932 [ warning sync.connectionvalidator ]:    QNetworkReply::NetworkError(ServiceUnavailableError) "Error transferring https://sub.domain.tld/status.php - server replied: " ""
01-05 21:06:01:932 [ info gui.account.state ]:  AccountState connection status change:  "Service unavailable" -> "Status not found"
01-05 21:06:01:932 [ info gui.account.state ]:  AccountState state change:  "Dienst nicht verf眉gbar" -> "Netzwerkfehler"
01-05 21:06:01:933 [ info gui.folder.manager ]: Account "[email protected]" disconnected or paused, terminating or descheduling sync folders
01-05 21:06:01:933 [ info gui.folder ]: folder  "1"  Terminating!
01-05 21:06:01:940 [ info gui.folder.manager ]: <========== Sync finished for folder [ownCloud] of account [[email protected]] with remote [https://sub.domain.tld/remote.php/dav/files/ncuser/]
01-05 21:06:17:416 [ info sync.connectionvalidator ]:   No system proxy set by OS
01-05 21:06:17:417 [ info sync.accessmanager ]: 2 "" "https://sub.domain.tld/status.php" has X-Request-ID "87098b4c-d64d-4255-b708-fc9fe8d8701e"
01-05 21:06:17:419 [ info sync.networkjob ]:    OCC::CheckServerJob created for "https://sub.domain.tld" + "status.php" "OCC::ConnectionValidator"
01-05 21:06:17:585 [ warning sync.networkjob ]: QNetworkReply::NetworkError(ServiceUnavailableError) "Error transferring https://sub.domain.tld/status.php - server replied: " QVariant(int, 503)
01-05 21:06:17:594 [ warning sync.networkjob.checkserver ]: error: status.php replied  503 ""
01-05 21:06:17:595 [ warning sync.connectionvalidator ]:    QNetworkReply::NetworkError(ServiceUnavailableError) "Error transferring https://sub.domain.tld/status.php - server replied: " ""
01-05 21:06:17:597 [ info gui.folder.manager ]: Account "[email protected]" disconnected or paused, terminating or descheduling sync folders
01-05 21:06:49:416 [ info sync.connectionvalidator ]:   No system proxy set by OS
01-05 21:06:49:419 [ info sync.accessmanager ]: 2 "" "https://sub.domain.tld/status.php" has X-Request-ID "bcf27b2c-452e-42b8-8c6b-8e85c14f4cc1"
01-05 21:06:49:422 [ info sync.networkjob ]:    OCC::CheckServerJob created for "https://sub.domain.tld" + "status.php" "OCC::ConnectionValidator"
01-05 21:06:49:612 [ warning sync.networkjob ]: QNetworkReply::NetworkError(ServiceUnavailableError) "Error transferring https://sub.domain.tld/status.php - server replied: " QVariant(int, 503)
01-05 21:06:49:615 [ warning sync.networkjob.checkserver ]: error: status.php replied  503 ""
01-05 21:06:49:618 [ warning sync.connectionvalidator ]:    QNetworkReply::NetworkError(ServiceUnavailableError) "Error transferring https://sub.domain.tld/status.php - server replied: " ""
01-05 21:06:49:621 [ info gui.folder.manager ]: Account "[email protected]" disconnected or paused, terminating or descheduling sync folders
agaida picture agaida on 5 Jan 2018

@ogoffart - the apache log you requested:

10.60.254.1 - - [05/Jan/2018:20:19:26 +0000] "PROPFIND /remote.php/dav/files/ncuser1/ HTTP/1.1" 207 2890 "-" "Mozilla/5.0 (Windows) mirall/2.3.3 (build 1) (Nextcloud)"
10.60.254.1 - - [05/Jan/2018:20:19:32 +0000] "PROPFIND /remote.php/dav/files/ncuser1/ HTTP/1.1" 207 1438 "-" "Mozilla/5.0 (Windows) mirall/2.3.3 (build 1) (Nextcloud)"
10.60.254.1 - - [05/Jan/2018:20:20:02 +0000] "PROPFIND /remote.php/dav/files/ncuser1/ HTTP/1.1" 207 2889 "-" "Mozilla/5.0 (Windows) mirall/2.3.3 (build 1) (Nextcloud)"
10.60.254.1 - - [05/Jan/2018:20:20:29 +0000] "GET /ocs/v2.php/apps/notifications/api/v1/notifications?format=json HTTP/1.1" 200 2179 "-" "Mozilla/5.0 (Windows) mirall/2.3.3 (build 1) (Nextcloud)"
10.60.254.1 - - [05/Jan/2018:20:20:32 +0000] "PROPFIND /remote.php/dav/files/ncuser1/ HTTP/1.1" 207 1438 "-" "Mozilla/5.0 (Windows) mirall/2.3.3 (build 1) (Nextcloud)"
10.60.254.1 - - [05/Jan/2018:20:20:57 +0000] "GET /status.php HTTP/1.1" 200 3049 "-" "Mozilla/5.0 (Linux) mirall/2.4.0"
10.60.254.1 - - [05/Jan/2018:20:20:57 +0000] "PROPFIND /remote.php/webdav/ HTTP/1.1" 207 1393 "-" "Mozilla/5.0 (Linux) mirall/2.4.0"
10.60.254.1 - - [05/Jan/2018:20:20:57 +0000] "GET /ocs/v1.php/config?format=json HTTP/1.1" 200 2632 "-" "Mozilla/5.0 (Linux) mirall/2.4.0"
10.60.254.1 - - [05/Jan/2018:20:20:57 +0000] "GET /ocs/v1.php/cloud/capabilities?format=json HTTP/1.1" 200 2596 "-" "Mozilla/5.0 (Linux) mirall/2.4.0"
10.60.254.1 - - [05/Jan/2018:20:20:57 +0000] "GET /ocs/v1.php/cloud/user?format=json HTTP/1.1" 200 1333 "-" "Mozilla/5.0 (Linux) mirall/2.4.0"
10.60.254.1 - - [05/Jan/2018:20:20:58 +0000] "GET /remote.php/dav/avatars/ncuser2/128.png HTTP/1.1" 503 1330 "-" "Mozilla/5.0 (Linux) mirall/2.4.0"
10.60.254.1 - - [05/Jan/2018:20:20:58 +0000] "GET /ocs/v1.php/cloud/activity?page=0&pagesize=100&format=json HTTP/1.1" 200 8040 "-" "Mozilla/5.0 (Linux) mirall/2.4.0"
10.60.254.1 - - [05/Jan/2018:20:20:58 +0000] "GET /ocs/v2.php/apps/notifications/api/v1/notifications?format=json HTTP/1.1" 200 927 "-" "Mozilla/5.0 (Linux) mirall/2.4.0"
10.60.254.1 - - [05/Jan/2018:20:20:58 +0000] "PROPFIND /remote.php/dav/files/ncuser2/ HTTP/1.1" 503 1322 "-" "Mozilla/5.0 (Linux) mirall/2.4.0"
10.60.254.1 - - [05/Jan/2018:20:21:02 +0000] "PROPFIND /remote.php/dav/files/ncuser1/ HTTP/1.1" 207 2889 "-" "Mozilla/5.0 (Windows) mirall/2.3.3 (build 1) (Nextcloud)"
10.60.254.1 - - [05/Jan/2018:20:21:11 +0000] "PROPFIND /remote.php/dav/files/ncuser2/ HTTP/1.1" 503 2575 "-" "Mozilla/5.0 (Linux) mirall/2.4.0"
10.60.254.1 - - [05/Jan/2018:20:21:28 +0000] "PROPFIND /remote.php/dav/files/ncuser2/ HTTP/1.1" 503 2575 "-" "Mozilla/5.0 (Linux) mirall/2.4.0"
10.60.254.1 - - [05/Jan/2018:20:21:28 +0000] "GET /status.php HTTP/1.1" 503 2575 "-" "Mozilla/5.0 (Linux) mirall/2.4.0"
10.60.254.1 - - [05/Jan/2018:20:21:32 +0000] "PROPFIND /remote.php/dav/files/ncuser1/ HTTP/1.1" 207 2889 "-" "Mozilla/5.0 (Windows) mirall/2.3.3 (build 1) (Nextcloud)"
10.60.254.1 - - [05/Jan/2018:20:22:00 +0000] "GET /status.php HTTP/1.1" 503 2575 "-" "Mozilla/5.0 (Linux) mirall/2.4.0"
10.60.254.1 - - [05/Jan/2018:20:22:02 +0000] "PROPFIND /remote.php/dav/files/ncuser1/ HTTP/1.1" 207 2889 "-" "Mozilla/5.0 (Windows) mirall/2.3.3 (build 1) (Nextcloud)"
agaida picture agaida on 5 Jan 2018

and here comes a cleaned nextcloud log - the places with f*word are places where sensible user informations like user or cleartext passwords was leaked into the log:

{"reqId":"rTgbSfOqgsmsHWh9fL4X","level":3,"time":"2017-12-13T12:29:27+00:00","remoteAddr":"10.60.254.1","user":"ncuser1","app":"appstoreFetcher","method":"GET","url":"\/index.php\/settings\/apps\/list?category=auth","message":"Exception: {\"Exception\":\"GuzzleHttp\\\\Exception\\\\ConnectException\",\"Message\":\"cURL error 28: Operation timed out after 10001 milliseconds with 0 out of 0 bytes received\",\"Code\":0,\"Trace\":\"#0 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/3rdparty\\\/guzzlehttp\\\/guzzle\\\/src\\\/RequestFsm.php(103): GuzzleHttp\\\\Exception\\\\RequestException::wrapException(Object(GuzzleHttp\\\\Message\\\\Request), Object(GuzzleHttp\\\\Ring\\\\Exception\\\\ConnectException))\\n#1 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/3rdparty\\\/guzzlehttp\\\/guzzle\\\/src\\\/RequestFsm.php(132): GuzzleHttp\\\\RequestFsm->__invoke(Object(GuzzleHttp\\\\Transaction))\\n#2 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/3rdparty\\\/react\\\/promise\\\/src\\\/FulfilledPromise.php(25): GuzzleHttp\\\\RequestFsm->GuzzleHttp\\\\{closure}(Array)\\n#3 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/3rdparty\\\/guzzlehttp\\\/ringphp\\\/src\\\/Future\\\/CompletedFutureValue.php(55): React\\\\Promise\\\\FulfilledPromise->then(Object(Closure), NULL, NULL)\\n#4 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/3rdparty\\\/guzzlehttp\\\/guzzle\\\/src\\\/Message\\\/FutureResponse.php(43): GuzzleHttp\\\\Ring\\\\Future\\\\CompletedFutureValue->then(Object(Closure), NULL, NULL)\\n#5 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/3rdparty\\\/guzzlehttp\\\/guzzle\\\/src\\\/RequestFsm.php(134): GuzzleHttp\\\\Message\\\\FutureResponse::proxy(Object(GuzzleHttp\\\\Ring\\\\Future\\\\CompletedFutureArray), Object(Closure))\\n#6 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/3rdparty\\\/guzzlehttp\\\/guzzle\\\/src\\\/Client.php(165): GuzzleHttp\\\\RequestFsm->__invoke(Object(GuzzleHttp\\\\Transaction))\\n#7 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/3rdparty\\\/guzzlehttp\\\/guzzle\\\/src\\\/Client.php(125): GuzzleHttp\\\\Client->send(Object(GuzzleHttp\\\\Message\\\\Request))\\n#8 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/private\\\/Http\\\/Client\\\/Client.php(138): GuzzleHttp\\\\Client->get('https:\\\/\\\/apps.ne...', Array)\\n#9 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/private\\\/App\\\/AppStore\\\/Fetcher\\\/Fetcher.php(99): OC\\\\Http\\\\Client\\\\Client->get('https:\\\/\\\/apps.ne...', Array)\\n#10 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/private\\\/App\\\/AppStore\\\/Fetcher\\\/AppFetcher.php(66): OC\\\\App\\\\AppStore\\\\Fetcher\\\\Fetcher->fetch('\\\"2017-12-13 07:...', '[{\\\"id\\\":\\\"ocsms\\\",...')\\n#11 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/private\\\/App\\\/AppStore\\\/Fetcher\\\/Fetcher.php(162): OC\\\\App\\\\AppStore\\\\Fetcher\\\\AppFetcher->fetch('\\\"2017-12-13 07:...', '[{\\\"id\\\":\\\"ocsms\\\",...')\\n#12 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/settings\\\/Controller\\\/AppSettingsController.php(169): OC\\\\App\\\\AppStore\\\\Fetcher\\\\Fetcher->get()\\n#13 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/settings\\\/Controller\\\/AppSettingsController.php(385): OC\\\\Settings\\\\Controller\\\\AppSettingsController->getAppsForCategory('auth')\\n#14 [internal function]: OC\\\\Settings\\\\Controller\\\\AppSettingsController->listApps('auth')\\n#15 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/private\\\/AppFramework\\\/Http\\\/Dispatcher.php(160): call_user_func_array(Array, Array)\\n#16 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/private\\\/AppFramework\\\/Http\\\/Dispatcher.php(90): OC\\\\AppFramework\\\\Http\\\\Dispatcher->executeController(Object(OC\\\\Settings\\\\Controller\\\\AppSettingsController), 'listApps')\\n#17 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/private\\\/AppFramework\\\/App.php(114): OC\\\\AppFramework\\\\Http\\\\Dispatcher->dispatch(Object(OC\\\\Settings\\\\Controller\\\\AppSettingsController), 'listApps')\\n#18 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/private\\\/AppFramework\\\/Routing\\\/RouteActionHandler.php(47): OC\\\\AppFramework\\\\App::main('OC\\\\\\\\Settings\\\\\\\\Con...', 'listApps', Object(OC\\\\AppFramework\\\\DependencyInjection\\\\DIContainer), Array)\\n#19 [internal function]: OC\\\\AppFramework\\\\Routing\\\\RouteActionHandler->__invoke(Array)\\n#20 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/private\\\/Route\\\/Router.php(299): call_user_func(Object(OC\\\\AppFramework\\\\Routing\\\\RouteActionHandler), Array)\\n#21 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/base.php(1004): OC\\\\Route\\\\Router->match('\\\/settings\\\/apps\\\/...')\\n#22 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/index.php(48): OC::handleRequest()\\n#23 {main}\",\"File\":\"\\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/3rdparty\\\/guzzlehttp\\\/guzzle\\\/src\\\/Exception\\\/RequestException.php\",\"Line\":49}","userAgent":"Mozilla\/5.0 (Windows NT 6.1; Win64; x64; rv:57.0) Gecko\/20100101 Firefox\/57.0","version":"12.0.4.3"}
{"reqId":"Rux1cxQgi9se2bEV4QTX","level":3,"time":"2017-12-13T12:29:40+00:00","remoteAddr":"10.60.254.1","user":"ncuser1","app":"appstoreFetcher","method":"GET","url":"\/index.php\/settings\/apps\/list?category=customization","message":"Exception: {\"Exception\":\"GuzzleHttp\\\\Exception\\\\ConnectException\",\"Message\":\"cURL error 28: Connection timed out after 10000 milliseconds\",\"Code\":0,\"Trace\":\"#0 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/3rdparty\\\/guzzlehttp\\\/guzzle\\\/src\\\/RequestFsm.php(103): GuzzleHttp\\\\Exception\\\\RequestException::wrapException(Object(GuzzleHttp\\\\Message\\\\Request), Object(GuzzleHttp\\\\Ring\\\\Exception\\\\ConnectException))\\n#1 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/3rdparty\\\/guzzlehttp\\\/guzzle\\\/src\\\/RequestFsm.php(132): GuzzleHttp\\\\RequestFsm->__invoke(Object(GuzzleHttp\\\\Transaction))\\n#2 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/3rdparty\\\/react\\\/promise\\\/src\\\/FulfilledPromise.php(25): GuzzleHttp\\\\RequestFsm->GuzzleHttp\\\\{closure}(Array)\\n#3 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/3rdparty\\\/guzzlehttp\\\/ringphp\\\/src\\\/Future\\\/CompletedFutureValue.php(55): React\\\\Promise\\\\FulfilledPromise->then(Object(Closure), NULL, NULL)\\n#4 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/3rdparty\\\/guzzlehttp\\\/guzzle\\\/src\\\/Message\\\/FutureResponse.php(43): GuzzleHttp\\\\Ring\\\\Future\\\\CompletedFutureValue->then(Object(Closure), NULL, NULL)\\n#5 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/3rdparty\\\/guzzlehttp\\\/guzzle\\\/src\\\/RequestFsm.php(134): GuzzleHttp\\\\Message\\\\FutureResponse::proxy(Object(GuzzleHttp\\\\Ring\\\\Future\\\\CompletedFutureArray), Object(Closure))\\n#6 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/3rdparty\\\/guzzlehttp\\\/guzzle\\\/src\\\/Client.php(165): GuzzleHttp\\\\RequestFsm->__invoke(Object(GuzzleHttp\\\\Transaction))\\n#7 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/3rdparty\\\/guzzlehttp\\\/guzzle\\\/src\\\/Client.php(125): GuzzleHttp\\\\Client->send(Object(GuzzleHttp\\\\Message\\\\Request))\\n#8 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/private\\\/Http\\\/Client\\\/Client.php(138): GuzzleHttp\\\\Client->get('https:\\\/\\\/apps.ne...', Array)\\n#9 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/private\\\/App\\\/AppStore\\\/Fetcher\\\/Fetcher.php(99): OC\\\\Http\\\\Client\\\\Client->get('https:\\\/\\\/apps.ne...', Array)\\n#10 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/private\\\/App\\\/AppStore\\\/Fetcher\\\/AppFetcher.php(66): OC\\\\App\\\\AppStore\\\\Fetcher\\\\Fetcher->fetch('\\\"2017-12-13 07:...', '[{\\\"id\\\":\\\"ocsms\\\",...')\\n#11 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/private\\\/App\\\/AppStore\\\/Fetcher\\\/Fetcher.php(162): OC\\\\App\\\\AppStore\\\\Fetcher\\\\AppFetcher->fetch('\\\"2017-12-13 07:...', '[{\\\"id\\\":\\\"ocsms\\\",...')\\n#12 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/settings\\\/Controller\\\/AppSettingsController.php(169): OC\\\\App\\\\AppStore\\\\Fetcher\\\\Fetcher->get()\\n#13 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/settings\\\/Controller\\\/AppSettingsController.php(385): OC\\\\Settings\\\\Controller\\\\AppSettingsController->getAppsForCategory('customization')\\n#14 [internal function]: OC\\\\Settings\\\\Controller\\\\AppSettingsController->listApps('customization')\\n#15 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/private\\\/AppFramework\\\/Http\\\/Dispatcher.php(160): call_user_func_array(Array, Array)\\n#16 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/private\\\/AppFramework\\\/Http\\\/Dispatcher.php(90): OC\\\\AppFramework\\\\Http\\\\Dispatcher->executeController(Object(OC\\\\Settings\\\\Controller\\\\AppSettingsController), 'listApps')\\n#17 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/private\\\/AppFramework\\\/App.php(114): OC\\\\AppFramework\\\\Http\\\\Dispatcher->dispatch(Object(OC\\\\Settings\\\\Controller\\\\AppSettingsController), 'listApps')\\n#18 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/private\\\/AppFramework\\\/Routing\\\/RouteActionHandler.php(47): OC\\\\AppFramework\\\\App::main('OC\\\\\\\\Settings\\\\\\\\Con...', 'listApps', Object(OC\\\\AppFramework\\\\DependencyInjection\\\\DIContainer), Array)\\n#19 [internal function]: OC\\\\AppFramework\\\\Routing\\\\RouteActionHandler->__invoke(Array)\\n#20 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/private\\\/Route\\\/Router.php(299): call_user_func(Object(OC\\\\AppFramework\\\\Routing\\\\RouteActionHandler), Array)\\n#21 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/base.php(1004): OC\\\\Route\\\\Router->match('\\\/settings\\\/apps\\\/...')\\n#22 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/index.php(48): OC::handleRequest()\\n#23 {main}\",\"File\":\"\\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/3rdparty\\\/guzzlehttp\\\/guzzle\\\/src\\\/Exception\\\/RequestException.php\",\"Line\":49}","userAgent":"Mozilla\/5.0 (Windows NT 6.1; Win64; x64; rv:57.0) Gecko\/20100101 Firefox\/57.0","version":"12.0.4.3"}
{"reqId":"dqw6uDQbFUdTwvNPqoy1","level":2,"time":"2017-12-20T18:58:24+00:00","remoteAddr":"10.60.254.1","user":"--","app":"core","method":"POST","url":"\/index.php\/login","message":"Login failed: 'ncuser2' (Remote IP: '10.60.254.1')","userAgent":"Mozilla\/5.0 (Windows NT 10.0; Win64; x64; rv:58.0) Gecko\/20100101 Firefox\/58.0","version":"12.0.4.3"}
{"reqId":"pyBGHZYCFOqQIld7pLaj","level":2,"time":"2017-12-21T11:07:55+00:00","remoteAddr":"10.60.254.1","user":"--","app":"core","method":"POST","url":"\/index.php\/login","message":"Login failed: 'ncuser2' (Remote IP: '10.60.254.1')","userAgent":"Mozilla\/5.0 (Windows NT 6.1; Win64; x64; rv:57.0) Gecko\/20100101 Firefox\/57.0","version":"12.0.4.3"}
{"reqId":"yWlZMk4lvPZrRxwLQt8e","level":3,"time":"2017-12-21T11:10:39+00:00","remoteAddr":"10.60.254.1","user":"ncuser2","app":"index","method":"POST","url":"\/index.php\/apps\/mail\/api\/accounts\/1\/send","message":"Exception: {\"Exception\":\"Exception\",\"Message\":\"Authenticated ciphertext could not be decoded.\",\"Code\":0,\"Trace\":\"#0 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/apps\\\/mail\\\/lib\\\/SMTP\\\/SmtpClientFactory.php(63): OC\\\\Security\\\\Crypto->decrypt(*** sensitive parameters replaced ***)\\n#1 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/apps\\\/mail\\\/lib\\\/Service\\\/MailTransmission.php(105): OCA\\\\Mail\\\\SMTP\\\\SmtpClientFactory->create(Object(OCA\\\\Mail\\\\Account))\\n#2 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/apps\\\/mail\\\/lib\\\/Controller\\\/AccountsController.php(229): OCA\\\\Mail\\\\Service\\\\MailTransmission->sendMessage('ncuser2', Object(OCA\\\\Mail\\\\Model\\\\NewMessageData), Object(OCA\\\\Mail\\\\Model\\\\RepliedMessageData), NULL, 771)\\n#3 [internal function]: OCA\\\\Mail\\\\Controller\\\\AccountsController->send(1, NULL, 'Facebook Kennwi...', '!!!!fucking-cleartext-password...!!!', '\\\"Fucking Cleartext Username\\\" <fuck...', '', '', 771, NULL, NULL, '')\\n#4 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/private\\\/AppFramework\\\/Http\\\/Dispatcher.php(160): call_user_func_array(Array, Array)\\n#5 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/private\\\/AppFramework\\\/Http\\\/Dispatcher.php(90): OC\\\\AppFramework\\\\Http\\\\Dispatcher->executeController(Object(OCA\\\\Mail\\\\Controller\\\\AccountsController), 'send')\\n#6 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/private\\\/AppFramework\\\/App.php(114): OC\\\\AppFramework\\\\Http\\\\Dispatcher->dispatch(Object(OCA\\\\Mail\\\\Controller\\\\AccountsController), 'send')\\n#7 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/private\\\/AppFramework\\\/Routing\\\/RouteActionHandler.php(47): OC\\\\AppFramework\\\\App::main('OCA\\\\\\\\Mail\\\\\\\\Contro...', 'send', Object(OC\\\\AppFramework\\\\DependencyInjection\\\\DIContainer), Array)\\n#8 [internal function]: OC\\\\AppFramework\\\\Routing\\\\RouteActionHandler->__invoke(Array)\\n#9 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/private\\\/Route\\\/Router.php(299): call_user_func(Object(OC\\\\AppFramework\\\\Routing\\\\RouteActionHandler), Array)\\n#10 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/base.php(1004): OC\\\\Route\\\\Router->match('\\\/apps\\\/mail\\\/api\\\/...')\\n#11 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/index.php(48): OC::handleRequest()\\n#12 {main}\",\"File\":\"\\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/private\\\/Security\\\/Crypto.php\",\"Line\":119}","userAgent":"Mozilla\/5.0 (Windows NT 6.1; Win64; x64; rv:57.0) Gecko\/20100101 Firefox\/57.0","version":"12.0.4.3"}
{"reqId":"XOyy6Fwnkv9XLUzqE6Gn","level":3,"time":"2017-12-21T11:11:38+00:00","remoteAddr":"10.60.254.1","user":"ncuser2","app":"index","method":"POST","url":"\/index.php\/apps\/mail\/api\/accounts\/1\/send","message":"Exception: {\"Exception\":\"Exception\",\"Message\":\"Authenticated ciphertext could not be decoded.\",\"Code\":0,\"Trace\":\"#0 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/apps\\\/mail\\\/lib\\\/SMTP\\\/SmtpClientFactory.php(63): OC\\\\Security\\\\Crypto->decrypt(*** sensitive parameters replaced ***)\\n#1 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/apps\\\/mail\\\/lib\\\/Service\\\/MailTransmission.php(105): OCA\\\\Mail\\\\SMTP\\\\SmtpClientFactory->create(Object(OCA\\\\Mail\\\\Account))\\n#2 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/apps\\\/mail\\\/lib\\\/Controller\\\/AccountsController.php(229): OCA\\\\Mail\\\\Service\\\\MailTransmission->sendMessage('ncuser2', Object(OCA\\\\Mail\\\\Model\\\\NewMessageData), Object(OCA\\\\Mail\\\\Model\\\\RepliedMessageData), NULL, 0)\\n#3 [internal function]: OCA\\\\Mail\\\\Controller\\\\AccountsController->send(1, NULL, 'Fratzenbuch', '!!!!fucking-cleartext-password...!!!', 'ncuser2@domain...', '', '', 0, NULL, NULL, '')\\n#4 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/private\\\/AppFramework\\\/Http\\\/Dispatcher.php(160): call_user_func_array(Array, Array)\\n#5 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/private\\\/AppFramework\\\/Http\\\/Dispatcher.php(90): OC\\\\AppFramework\\\\Http\\\\Dispatcher->executeController(Object(OCA\\\\Mail\\\\Controller\\\\AccountsController), 'send')\\n#6 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/private\\\/AppFramework\\\/App.php(114): OC\\\\AppFramework\\\\Http\\\\Dispatcher->dispatch(Object(OCA\\\\Mail\\\\Controller\\\\AccountsController), 'send')\\n#7 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/private\\\/AppFramework\\\/Routing\\\/RouteActionHandler.php(47): OC\\\\AppFramework\\\\App::main('OCA\\\\\\\\Mail\\\\\\\\Contro...', 'send', Object(OC\\\\AppFramework\\\\DependencyInjection\\\\DIContainer), Array)\\n#8 [internal function]: OC\\\\AppFramework\\\\Routing\\\\RouteActionHandler->__invoke(Array)\\n#9 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/private\\\/Route\\\/Router.php(299): call_user_func(Object(OC\\\\AppFramework\\\\Routing\\\\RouteActionHandler), Array)\\n#10 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/base.php(1004): OC\\\\Route\\\\Router->match('\\\/apps\\\/mail\\\/api\\\/...')\\n#11 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/index.php(48): OC::handleRequest()\\n#12 {main}\",\"File\":\"\\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/private\\\/Security\\\/Crypto.php\",\"Line\":119}","userAgent":"Mozilla\/5.0 (Windows NT 6.1; Win64; x64; rv:57.0) Gecko\/20100101 Firefox\/57.0","version":"12.0.4.3"}
{"reqId":"hp6xJDqRdtULgWR797pD","level":3,"time":"2017-12-21T11:11:47+00:00","remoteAddr":"10.60.254.1","user":"ncuser2","app":"index","method":"POST","url":"\/index.php\/apps\/mail\/api\/accounts\/1\/send","message":"Exception: {\"Exception\":\"Exception\",\"Message\":\"Authenticated ciphertext could not be decoded.\",\"Code\":0,\"Trace\":\"#0 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/apps\\\/mail\\\/lib\\\/SMTP\\\/SmtpClientFactory.php(63): OC\\\\Security\\\\Crypto->decrypt(*** sensitive parameters replaced ***)\\n#1 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/apps\\\/mail\\\/lib\\\/Service\\\/MailTransmission.php(105): OCA\\\\Mail\\\\SMTP\\\\SmtpClientFactory->create(Object(OCA\\\\Mail\\\\Account))\\n#2 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/apps\\\/mail\\\/lib\\\/Controller\\\/AccountsController.php(229): OCA\\\\Mail\\\\Service\\\\MailTransmission->sendMessage('ncuser2', Object(OCA\\\\Mail\\\\Model\\\\NewMessageData), Object(OCA\\\\Mail\\\\Model\\\\RepliedMessageData), NULL, 773)\\n#3 [internal function]: OCA\\\\Mail\\\\Controller\\\\AccountsController->send(1, NULL, 'Fratzenbuch', '!!!!fucking-cleartext-password...!!!', 'ncuser2@cleartextdomain...', '', '', 773, NULL, NULL, '')\\n#4 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/private\\\/AppFramework\\\/Http\\\/Dispatcher.php(160): call_user_func_array(Array, Array)\\n#5 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/private\\\/AppFramework\\\/Http\\\/Dispatcher.php(90): OC\\\\AppFramework\\\\Http\\\\Dispatcher->executeController(Object(OCA\\\\Mail\\\\Controller\\\\AccountsController), 'send')\\n#6 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/private\\\/AppFramework\\\/App.php(114): OC\\\\AppFramework\\\\Http\\\\Dispatcher->dispatch(Object(OCA\\\\Mail\\\\Controller\\\\AccountsController), 'send')\\n#7 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/private\\\/AppFramework\\\/Routing\\\/RouteActionHandler.php(47): OC\\\\AppFramework\\\\App::main('OCA\\\\\\\\Mail\\\\\\\\Contro...', 'send', Object(OC\\\\AppFramework\\\\DependencyInjection\\\\DIContainer), Array)\\n#8 [internal function]: OC\\\\AppFramework\\\\Routing\\\\RouteActionHandler->__invoke(Array)\\n#9 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/private\\\/Route\\\/Router.php(299): call_user_func(Object(OC\\\\AppFramework\\\\Routing\\\\RouteActionHandler), Array)\\n#10 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/base.php(1004): OC\\\\Route\\\\Router->match('\\\/apps\\\/mail\\\/api\\\/...')\\n#11 \\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/index.php(48): OC::handleRequest()\\n#12 {main}\",\"File\":\"\\\/home\\\/nextcloud\\\/ncuser1\\\/nextcloud\\\/lib\\\/private\\\/Security\\\/Crypto.php\",\"Line\":119}","userAgent":"Mozilla\/5.0 (Windows NT 6.1; Win64; x64; rv:57.0) Gecko\/20100101 Firefox\/57.0","version":"12.0.4.3"}
{"reqId":"6BWu73UDG6xP9ohzDGHU","level":3,"time":"2017-12-21T11:19:36+00:00","remoteAddr":"10.60.254.1","user":"ncuser2","app":"PHP","method":"GET","url":"\/index.php\/apps\/mail\/api\/accounts\/1\/folders\/SU5CT1g=\/messages\/247018\/html","message":"Attempted to retrieve non-existent variable CurrentAttr at \/home\/nextcloud\/ncuser1\/nextcloud\/apps\/mail\/vendor\/ezyang\/htmlpurifier\/library\/HTMLPurifier\/Context.php#48","userAgent":"Mozilla\/5.0 (Windows NT 6.1; Win64; x64; rv:57.0) Gecko\/20100101 Firefox\/57.0","version":"12.0.4.3"}
{"reqId":"6BWu73UDG6xP9ohzDGHU","level":3,"time":"2017-12-21T11:19:36+00:00","remoteAddr":"10.60.254.1","user":"ncuser2","app":"PHP","method":"GET","url":"\/index.php\/apps\/mail\/api\/accounts\/1\/folders\/SU5CT1g=\/messages\/247018\/html","message":"Attempted to retrieve non-existent variable CurrentAttr at \/home\/nextcloud\/ncuser1\/nextcloud\/apps\/mail\/vendor\/ezyang\/htmlpurifier\/library\/HTMLPurifier\/Context.php#48","userAgent":"Mozilla\/5.0 (Windows NT 6.1; Win64; x64; rv:57.0) Gecko\/20100101 Firefox\/57.0","version":"12.0.4.3"}
{"reqId":"brNvaLi1Z4Ty8Lv1lhxO","level":3,"time":"2017-12-24T07:57:10+00:00","remoteAddr":"10.60.254.1","user":"dmahne","app":"PHP","method":"GET","url":"\/index.php\/apps\/dashboard\/activities?_=1514102271711","message":"Undefined index: link at \/home\/nextcloud\/ncuser1\/nextcloud\/apps\/dashboard\/lib\/Service\/ActivityService.php#104","userAgent":"Mozilla\/5.0 (Windows NT 6.1; Win64; x64; rv:57.0) Gecko\/20100101 Firefox\/57.0","version":"12.0.4.3"}
{"reqId":"brNvaLi1Z4Ty8Lv1lhxO","level":3,"time":"2017-12-24T07:57:10+00:00","remoteAddr":"10.60.254.1","user":"dmahne","app":"PHP","method":"GET","url":"\/index.php\/apps\/dashboard\/activities?_=1514102271711","message":"Undefined index: link at \/home\/nextcloud\/ncuser1\/nextcloud\/apps\/dashboard\/lib\/Service\/ActivityService.php#104","userAgent":"Mozilla\/5.0 (Windows NT 6.1; Win64; x64; rv:57.0) Gecko\/20100101 Firefox\/57.0","version":"12.0.4.3"}
{"reqId":"nuh8urCswImmGTpiK0mJ","level":2,"time":"2018-01-02T20:09:28+00:00","remoteAddr":"10.60.254.1","user":"--","app":"core","method":"PROPFIND","url":"\/remote.php\/dav\/files\/ncuser2\/","message":"Login failed: 'ncuser2' (Remote IP: '10.60.254.1')","userAgent":"Mozilla\/5.0 (Linux) mirall\/2.4.0","version":"12.0.4.3"}
{"reqId":"iVNGVTHtjOu4O8337X8F","level":2,"time":"2018-01-02T20:09:34+00:00","remoteAddr":"10.60.254.1","user":"--","app":"core","method":"PROPFIND","url":"\/remote.php\/dav\/files\/ncuser2\/","message":"Login failed: 'ncuser2' (Remote IP: '10.60.254.1')","userAgent":"Mozilla\/5.0 (Linux) mirall\/2.4.0","version":"12.0.4.3"}

btw - i'm not the user who wrote the debian bug - so we are at least two unhappy users - and more will follow, if owncloud hit testing

agaida picture agaida on 5 Jan 2018

I have the same issue with nextcloud 12.0.4 and owncloud-client 2.4.0. Downgrading the owncloud-client to 2.3.x solved the issue for me as well.

NGINX complains that fastcgi returned '0' for remote.php when accessed with owncloud-client 2.4.0. No errors from fpm is outputted.

DeltoidDelta picture DeltoidDelta on 7 Jan 2018

The log does not tell much, what's interesting is:

10.60.254.1 - - [05/Jan/2018:20:20:58 +0000] "PROPFIND /remote.php/dav/files/ncuser2/ HTTP/1.1" 503 1322 "-" "Mozilla/5.0 (Linux) mirall/2.4.0"

Maybe this corresponds to 

{"reqId":"nuh8urCswImmGTpiK0mJ","level":2,"time":"2018-01-02T20:09:28+00:00","remoteAddr":"10.60.254.1","user":"--","app":"core","method":"PROPFIND","url":"\/remote.php\/dav\/files\/ncuser2\/","message":"Login failed: 'ncuser2' (Remote IP: '10.60.254.1')","userAgent":"Mozilla\/5.0 (Linux) mirall\/2.4.0","version":"12.0.4.3"}

So the error would be login failed.
But there should be more investigation done on the server to find out why.

In 2.4, we changed a bit the authentication worflow in order to support oauth, but we don't have information on what is wrong.
Please report the problem to Nextcloud. They should investigate what the problem is. Then, once we know exactly what the client do that triggres this problem, we can attempt to work around it.

ogoffart picture ogoffart on 8 Jan 2018

I just checked with a Nextcloud 12 demo instance and saw the issue at hand; the server is replying to GET https://<nextcloud>/remote.php/webdav/with a WWW-Authenticate: Bearer realm="Nextcloud" header. This triggers the OAuth2 (https://github.com/owncloud/client/pull/5668) authentication mechanism on the client, while the server does not support this behavior (described in https://github.com/owncloud/oauth2/blob/master/README.md)

The 503 error you see on the server logs/client is the result of opening https://<nextcloud>/index.php/apps/oauth2/authorize?response_type=code&client_id=<id>&redirect_uri=<url> in the browser (the /apps/oauth2/authorize path doesn't exist since the app is not installed).

SamuAlfageme picture SamuAlfageme on 8 Jan 2018
👍1

@jospoortvliet @rullzer

guruz picture guruz on 8 Jan 2018

I tested a bunch of different setups.

  • Apache - Nc 12.0.4
  • Apache - Nc 13 RC1
  • Nginx - NC 12.0.4
  • Nginx - NC 13 RC1

And for me it all worked. Except the demo.nextcloud.com . However as some users also reported it I suspect some webserver config magic. If anybody can share their webserver config?

rullzer picture rullzer on 18 Jan 2018

In the debug log of the owncloud client I can find the following line:
01-20 03:19:28:703 [ debug qt.network.http2 ] [ unknown ]: stream 1 closed

And indeed the client woks again as soon as I deactivate http2 in my nginx config.

The strange thing is: demo.nextcloud.com doesn't support http2. So may be there is another problem.?

bastei picture bastei on 20 Jan 2018

So there might be different problem in play here. The problem on the nextcloud demo server might not be the same as what other reports. Please be explicit about your webserver. and the symptom of the problem.

@bastei: Do you see the errors 503, like @hefee reports.
@hefee / @agaida : are you using HTTP/2 ?

You can see if you are using http/2 because of a log message like this when starting the sync: Server "10.0.2.1" Using HTTP/2

HTTP/2 was not tested so good because the version of Qt that is shipped by owncloud is still Qt 5.6 which does not support it. However HTTP/2 works for me with apache and owncloud 10.

(btw, @bastei , this stream closed message is normal.)

ogoffart picture ogoffart on 20 Jan 2018

I get the 503 errors, too:
01-20 10:34:36:099 [ warning sync.networkjob ]: QNetworkReply::NetworkError(ServiceUnavailableError) "Error transferring https://yyyyy/remote.php/dav/files/xxxxx/ - server replied: " QVariant(int, 503)

nginx 1.10.3 (http2 enabled)
Nextcloud 12.0.4.3
owncloud-client 2.4.0+dfsg-1 (Debian testing; using Qt 5.9.2 SSL library OpenSSL 1.0.2n)

bastei picture bastei on 20 Jan 2018

ogoffart - yes, i use http2
proxy apache2/sid
nginx with default http2 config/sid
owncloud-client downgraded to latest 2.3.x from testing

agaida picture agaida on 20 Jan 2018

I use NGINX with HTTP/2 as well for my Nextcloud 12.0.4.3. My owncloud-client is built with LibreSSL (2.5.5) on qt 5.9.3.

DeltoidDelta picture DeltoidDelta on 22 Jan 2018

@agaida on your server logs, all the requests appear w/HTTP/1.1. I'm guessing the proxy is handling the HTTP/2 traffic. Can you inspect the logs there?

@bastei @simdol do you guys happen to have any proxy/server logs when the issue pops out?

SamuAlfageme picture SamuAlfageme on 30 Jan 2018

@SamuAlfageme: Here are the server logs from the moment the affected owncloud client starts:

[30/Jan/2018:22:43:51 +0000] 0.0.0.0 - username "Mozilla/5.0 (Linux) mirall/2.4.0" - "GET /status.php HTTP/2.0" 200 1180
[30/Jan/2018:22:43:51 +0000] 0.0.0.0 - username "Mozilla/5.0 (Linux) mirall/2.4.0" - "PROPFIND /remote.php/webdav/ HTTP/2.0" 207 915
[30/Jan/2018:22:43:51 +0000] 0.0.0.0 - username "Mozilla/5.0 (Linux) mirall/2.4.0" - "GET /ocs/v1.php/config?format=json HTTP/2.0" 200 870
[30/Jan/2018:22:43:51 +0000] 0.0.0.0 - username "Mozilla/5.0 (Linux) mirall/2.4.0" - "GET /ocs/v1.php/cloud/capabilities?format=json HTTP/2.0" 200 1982
[30/Jan/2018:22:43:52 +0000] 0.0.0.0 - username "Mozilla/5.0 (Linux) mirall/2.4.0" - "GET /ocs/v1.php/cloud/user?format=json HTTP/2.0" 200 996
[30/Jan/2018:22:43:52 +0000] 0.0.0.0 - username "Mozilla/5.0 (Linux) mirall/2.4.0" - "GET /remote.php/dav/avatars/username/128.png HTTP/2.0" 503 805
[30/Jan/2018:22:43:52 +0000] 0.0.0.0 - username "Mozilla/5.0 (Linux) mirall/2.4.0" - "GET /ocs/v1.php/cloud/activity?page=0&pagesize=100&format=json HTTP/2.0" 200 1013
[30/Jan/2018:22:43:53 +0000] 0.0.0.0 - username "Mozilla/5.0 (Linux) mirall/2.4.0" - "GET /ocs/v2.php/apps/notifications/api/v1/notifications?format=json HTTP/2.0" 200 654
[30/Jan/2018:22:43:53 +0000] 0.0.0.0 - username "Mozilla/5.0 (Linux) mirall/2.4.0" - "PROPFIND /remote.php/dav/files/username/ HTTP/2.0" 503 642
bastei picture bastei on 30 Jan 2018

@bastei I see both 507 coming from the (new)/remote.php/dav/ endpoint. Can you try to run the client with OWNCLOUD_CHUNKING_NG=0? - I don't know the state of NC regarding Chunking-ng, but client should pick the right option from the capabilities: ref. https://github.com/owncloud/core/commit/eadcffcf309c74d024f745ddf2c810e72d686fae

SamuAlfageme picture SamuAlfageme on 31 Jan 2018

@SamuAlfageme Unfortunately the logs are very familiar with OWNCLOUD_CHUNKING_NG=0. Here is the server log (from starting the client until closing it):

[31/Jan/2018:09:34:12 +0000] 0.0.0.0 - username "Mozilla/5.0 (Linux) mirall/2.4.0" - "GET /status.php HTTP/2.0" 200 1180
[31/Jan/2018:09:34:12 +0000] 0.0.0.0 - username "Mozilla/5.0 (Linux) mirall/2.4.0" - "PROPFIND /remote.php/webdav/ HTTP/2.0" 207 915
[31/Jan/2018:09:34:12 +0000] 0.0.0.0 - username "Mozilla/5.0 (Linux) mirall/2.4.0" - "GET /ocs/v1.php/config?format=json HTTP/2.0" 200 867
[31/Jan/2018:09:34:12 +0000] 0.0.0.0 - username "Mozilla/5.0 (Linux) mirall/2.4.0" - "GET /ocs/v1.php/cloud/capabilities?format=json HTTP/2.0" 200 1979
[31/Jan/2018:09:34:13 +0000] 0.0.0.0 - username "Mozilla/5.0 (Linux) mirall/2.4.0" - "GET /ocs/v1.php/cloud/user?format=json HTTP/2.0" 200 990
[31/Jan/2018:09:34:13 +0000] 0.0.0.0 - username "Mozilla/5.0 (Linux) mirall/2.4.0" - "GET /remote.php/dav/avatars/username/128.png HTTP/2.0" 503 810
[31/Jan/2018:09:34:13 +0000] 0.0.0.0 - username "Mozilla/5.0 (Linux) mirall/2.4.0" - "GET /ocs/v1.php/cloud/activity?page=0&pagesize=100&format=json HTTP/2.0" 200 1017
[31/Jan/2018:09:34:13 +0000] 0.0.0.0 - username "Mozilla/5.0 (Linux) mirall/2.4.0" - "PROPFIND /remote.php/webdav/ HTTP/2.0" 503 799
[31/Jan/2018:09:34:14 +0000] 0.0.0.0 - username "Mozilla/5.0 (Linux) mirall/2.4.0" - "GET /ocs/v2.php/apps/notifications/api/v1/notifications?format=json HTTP/2.0" 200 652
[31/Jan/2018:09:34:14 +0000] 0.0.0.0 - username "Mozilla/5.0 (Linux) mirall/2.4.0" - "PROPFIND /remote.php/webdav/ HTTP/2.0" 503 643
[31/Jan/2018:09:34:19 +0000] 0.0.0.0 - username "Mozilla/5.0 (Linux) mirall/2.4.0" - "PROPFIND /remote.php/webdav/ HTTP/2.0" 503 641
[31/Jan/2018:09:35:27 +0000] 0.0.0.0 - username "Mozilla/5.0 (Linux) mirall/2.4.0" - "GET /status.php HTTP/2.0" 200 1172
[31/Jan/2018:09:35:28 +0000] 0.0.0.0 - username "Mozilla/5.0 (Linux) mirall/2.4.0" - "PROPFIND /remote.php/webdav/ HTTP/2.0" 207 914
[31/Jan/2018:09:35:28 +0000] 0.0.0.0 - username "Mozilla/5.0 (Linux) mirall/2.4.0" - "GET /ocs/v1.php/config?format=json HTTP/2.0" 200 864
[31/Jan/2018:09:35:28 +0000] 0.0.0.0 - username "Mozilla/5.0 (Linux) mirall/2.4.0" - "GET /ocs/v1.php/cloud/capabilities?format=json HTTP/2.0" 200 1983
[31/Jan/2018:09:35:28 +0000] 0.0.0.0 - username "Mozilla/5.0 (Linux) mirall/2.4.0" - "GET /ocs/v1.php/cloud/user?format=json HTTP/2.0" 200 993
[31/Jan/2018:09:35:29 +0000] 0.0.0.0 - username "Mozilla/5.0 (Linux) mirall/2.4.0" - "GET /remote.php/dav/avatars/username/128.png HTTP/2.0" 503 809
[31/Jan/2018:09:35:29 +0000] 0.0.0.0 - username "Mozilla/5.0 (Linux) mirall/2.4.0" - "GET /ocs/v1.php/cloud/activity?page=0&pagesize=100&format=json HTTP/2.0" 200 1022
[31/Jan/2018:09:35:29 +0000] 0.0.0.0 - username "Mozilla/5.0 (Linux) mirall/2.4.0" - "GET /ocs/v2.php/apps/notifications/api/v1/notifications?format=json HTTP/2.0" 200 654
[31/Jan/2018:09:35:39 +0000] 0.0.0.0 - username "Mozilla/5.0 (Linux) mirall/2.4.0" - "PROPFIND /remote.php/webdav/ HTTP/2.0" 503 642
[31/Jan/2018:09:35:39 +0000] 0.0.0.0 - username "Mozilla/5.0 (Linux) mirall/2.4.0" - "PROPFIND /remote.php/webdav/ HTTP/2.0" 503 643
[31/Jan/2018:09:35:39 +0000] 0.0.0.0 - username "Mozilla/5.0 (Linux) mirall/2.4.0" - "PROPFIND /remote.php/webdav/ HTTP/2.0" 503 643
[31/Jan/2018:09:35:44 +0000] 0.0.0.0 - username "Mozilla/5.0 (Linux) mirall/2.4.0" - "PROPFIND /remote.php/webdav/ HTTP/2.0" 503 643
[31/Jan/2018:09:35:49 +0000] 0.0.0.0 - username "Mozilla/5.0 (Linux) mirall/2.4.0" - "GET /ocs/v2.php/apps/notifications/api/v1/notifications?format=json HTTP/2.0" 200 495
[31/Jan/2018:09:35:49 +0000] 0.0.0.0 - username "Mozilla/5.0 (Linux) mirall/2.4.0" - "PROPFIND /remote.php/webdav/ HTTP/2.0" 503 641
[31/Jan/2018:09:36:06 +0000] 0.0.0.0 - username "Mozilla/5.0 (Linux) mirall/2.4.0" - "GET /ocs/v2.php/apps/notifications/api/v1/notifications?format=json HTTP/2.0" 200 495
[31/Jan/2018:09:36:07 +0000] 0.0.0.0 - username "Mozilla/5.0 (Linux) mirall/2.4.0" - "PROPFIND /remote.php/webdav/ HTTP/2.0" 503 641
[31/Jan/2018:09:36:07 +0000] 0.0.0.0 - username "Mozilla/5.0 (Linux) mirall/2.4.0" - "PROPFIND /remote.php/webdav/ HTTP/2.0" 503 642
[31/Jan/2018:09:36:07 +0000] 0.0.0.0 - username "Mozilla/5.0 (Linux) mirall/2.4.0" - "PROPFIND /remote.php/webdav/ HTTP/2.0" 503 644
[31/Jan/2018:09:36:07 +0000] 0.0.0.0 - username "Mozilla/5.0 (Linux) mirall/2.4.0" - "GET /status.php HTTP/2.0" 503 643

So, remote.php/webdav/ is affected just as remote.php/dav/ and even status.php.

bastei picture bastei on 31 Jan 2018

I confirm this bug is still happening with Nextcloud 13.

I confirm this bug disappeared when not using HTTP/2 with the nginx configuration.

I repeat: disabling HTTP/2 solves this issue.

However, this is not a workaround for me. I need HTTP/2 for other websites my server is serving.

Glandos picture Glandos on 7 Feb 2018
👍1

Is it only @Glandos for who HTTP2 is the reason... ?
What about @bastei @simdol @hefee @agaida ?
Can you guys also check the Qt version mentioned in the settings dialog "General" tab?

guruz picture guruz on 8 Feb 2018

Qt version on Debian unstable is currently: 5.9.2+dfsg-9

What about @bastei @simdol @hefee @agaida ?
I can't tell - 'cause I have no nextcloud running ( I'm "just" the mantainer of occ in Debian, that reported things upstream.)

hefee picture hefee on 8 Feb 2018

Is it only @Glandos for who HTTP2 is the reason... ?

#issuecomment-359139205

Can you guys also check the Qt version

#issuecomment-359159964

bastei picture bastei on 8 Feb 2018
😕1

@bastei @Glandos Would be interesting to see if you can compile the client with Qt 5.10 (or 5.9.4) and if this makes a difference. https://doc.owncloud.org/desktop/2.4/building.html
(although that might be a pain to do...)

Or you give out a test account to @ogoffart who has a newer Qt? e-mail is his github at woboq.com ...

@hefee When does debian switch to Qt 5.9.4?

The problem could be https://bugreports.qt.io/browse/QTBUG-64359

guruz picture guruz on 8 Feb 2018

I'm lost the interest in this issue nearly fully - my server configuration is fine, the 2.4 Windows client works fine. Version:
```
Gebaut von der GIT-Revision 9a1f73 auf Dec 21 2017, 17:00:11 verwendet Qt 5.6.2, OpenSSL 1.0.2n 7 Dec 2017
````
So my only guess is the used ssl version in debian - anyways, happy debugging.

EDIT: installed the obs packages on a current sid - works fine:
Built from Git revision 9a1f73 on Dec 21 2017, 18:29:50 using Qt 5.6.2, OpenSSL 1.0.2n 7 Dec 2017

So until it is solved i will use the 2.3.x client

agaida picture agaida on 8 Feb 2018

On openSuse Tumbleweed:

02-09 11:30:18:617 [ info gui.folder ]: Client version 2.4.0  Qt 5.10.0  SSL  OpenSSL 1.1.0g-fips  2 Nov 2017
02-09 11:30:18:618 [ info gui.folder ]: SyncEngine finished without problem.

The RPM info (sorry for localized field names):

D茅p么t                     : repo-oss                           
Nom                       : owncloud-client                    
Version                   : 2.4.0-1.1                          
Arch                      : x86_64                             
Fabricant聽                : openSUSE                           
Taille une fois install茅聽 : 2,9 MiB                            
install茅                  : Non                                
脡tat                      : non install茅                       
Paquet source             : owncloud-client-2.4.0-1.1.src

So, it seems that the Debian build is to blame. Qt 5.10 is in experimental, but I don't know how long it will take to make it into unstable.

So @hefee if you can report on the Debian bug that this is linked to a combination of Qt version and HTTP/2 server, it seems the root cause.

Glandos picture Glandos on 9 Feb 2018

EDIT: installed the obs packages on a current sid - works fine:
Built from Git revision 9a1f73 on Dec 21 2017, 18:29:50 using Qt 5.6.2, OpenSSL 1.0.2n 7 Dec 2017

@agaida That one works because we disable HTTP2 with this version.

@Glandos thanks for verifying Qt 5.10.0 works with HTTP2.

guruz picture guruz on 9 Feb 2018

Has anyone reprduced the bug with owncloud rather than nextcloud? (@SamuAlfageme, did you ?)

Anybody else tried upgrading Qt to solve the problem? Since @Glandos went from debian to opensuse, there might be other factor in play (such as the openssl version)

Even then , we don't have confirmation this is not a server issue? What are the nextcloud server log saying about this error 503? Why is it happening?

ogoffart picture ogoffart on 12 Feb 2018

@ogoffart :

I confirm this bug disappeared when not using HTTP/2 with the nginx configuration.

In one test (on Debian), I only disabled http2 on my nginx server. No less, no more. And without HTTP/2, it worked.
It can be an issue with openssl, but it would be very surprising.

Glandos picture Glandos on 12 Feb 2018

@ogoffart about

Has anyone reprduced the bug with owncloud rather than nextcloud?

Nope, been poking an ownCloud 10.0.4 deployed with nginx over HTTP/2 for a bit and got no traces whatsoever of errors 5XX that could be attributed to the protocol bump. I think the conditions to reproduce this are highly dependent on how the server was deployed (env-wise)

We do have daily builds w/ Qt 5.10 already available in https://build.opensuse.org/package/show/isv:ownCloud:testpilot:daily:master/testpilotcloud-client @bastei @Glandos @agaida @hefee care to give it a spin?

Nextcloud/Apache logs (or even stack traces if we're looking at concurrency issues) from the time of the incidents will come in very handy to determine why the server is misbehaving and which client requests lead to that.

SamuAlfageme picture SamuAlfageme on 12 Feb 2018

@Glandos : but the opensuse build works even with HTTP/2 ?
( I was mentioning openssl version because it is the cause of QTBUG-65849)

ogoffart picture ogoffart on 12 Feb 2018

@ogoffart Yes.

Glandos picture Glandos on 12 Feb 2018

I'm quite sure it is QTBUG-64359 :-)

So I consider this fixed with #6353

guruz picture guruz on 12 Feb 2018

Has anyone seen issues with HTTP2 in 2.6.0 similar as in https://github.com/owncloud/client/issues/7610 ? Please comment there...

guruz picture guruz on 3 Dec 2019
Was this page helpful?
0 / 5 - 0 ratings

Related issues

ymakhloufi picture ymakhloufi  路  3Comments
guruz picture guruz  路  4Comments
jnweiger picture jnweiger  路  5Comments
vco1 picture vco1  路  3Comments
xmana picture xmana  路  5Comments