Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

"403 Forbidden" to "MOVE" syncing large files #33119

Closed
sgparry opened this issue Oct 10, 2018 · 23 comments
Closed

"403 Forbidden" to "MOVE" syncing large files #33119

sgparry opened this issue Oct 10, 2018 · 23 comments

Comments

@sgparry
Copy link

sgparry commented Oct 10, 2018

I am reporting this on the core component because the origin of the problem seems to be server side, even though it only occurs with the latest sync client (2.5.0 Build 10560 running on Microsoft Windows). When trying to sync some large files I get errors like this in the client log:

10/10/2018 06:13:57,pyspace repository/CA-GCE-COMPSCI/Papers/a2-past-papers/H446-01 QP Jun18_Accessible.pdf, ownCloud,Server replied "403 Forbidden" to "MOVE https://owncloud.mainscreen.com/remote.php/dav/uploads/1f58a300-382a-1032-88a7-719ff25ec74a/2147239545/.file" (Requested uri (//remote.php/dav/files/1f58a300-382a-1032-88a7-719ff25ec74a/pyspace%20repository/CA-GCE-COMPSCI/Papers/a2-past-papers/H446-01%20QP%20Jun18_Accessible.pdf) is out of base uri (/remote.php/dav/))

I have tried the .htaccess patch suggested under some other bug reports but to no avail.
Not sure if this is a factor, but most of my non-owncloud web content is under /srv, not /var

Steps to reproduce

  1. Copy a 28MB file to your local owncloud folder
  2. Wait until the client attempts to sync.

Expected behaviour

File should be synced and green tick appear

Actual behaviour

Red x appears and above error is found in "Not synced"

Server configuration

Operating system:
Distributor ID: Ubuntu
Description: Ubuntu 16.04.5 LTS
Release: 16.04
Codename: xenial
Linux mainscreen.com 4.14.74-rh91-20181005000331.xenU.i386 #1 SMP Fri Oct 5 00:08:45 UTC 2018 i686 i686 i686 GNU/Linux

Web server:
apache2/xenial-updates,now 2.4.18-2ubuntu3.9 i386

Database:
mysql-community-server/unknown,now 5.7.23-1ubuntu14.04

PHP version:
PHP 7.0.32-0ubuntu0.16.04.1 (cli) ( NTS )
Copyright (c) 1997-2017 The PHP Group
Zend Engine v3.0.0, Copyright (c) 1998-2017 Zend Technologies
with Zend OPcache v7.0.32-0ubuntu0.16.04.1, Copyright (c) 1999-2017, by Zend Technologies

ownCloud version: (see ownCloud admin page)

version 10.0.10.4
versionstring 10.0.10
edition Community
productname ownCloud

Updated from an older ownCloud or fresh install:
updated

Where did you install ownCloud from:
apt repositories:
deb http://download.owncloud.org/download/repositories/10.0/Ubuntu_16.04/ /

Signing status (ownCloud 9.0 and above):
No errors have been found.

The content of config/config.php:
{
"system": {
"instanceid": "oc420f76f058",
"passwordsalt": "REMOVED SENSITIVE VALUE",
"datadirectory": "/var/www/owncloud/data",
"dbtype": "mysql",
"version": "10.0.10.4",
"dbname": "mainscreen_owncloud",
"dbhost": "localhost",
"dbtableprefix": "oc_",
"dbuser": "REMOVED SENSITIVE VALUE",
"dbpassword": "REMOVED SENSITIVE VALUE",
"installed": true,
"ldapIgnoreNamingRules": false,
"theme": "",
"maintenance": false,
"loglevel": 1,
"trusted_domains": [
"owncloud.mainscreen.com"
],
"secret": "REMOVED SENSITIVE VALUE",
"memcache.local": "\OC\Memcache\APCu",
"memcache.locking": "\OC\Memcache\Redis",
"redis": {
"host": "localhost",
"port": 6379
},
"appstore.experimental.enabled": true,
"trashbin_retention_obligation": "auto",
"updatechecker": false,
"files_external_allow_create_new_local": "true",
"singleuser": false
}
}

List of activated apps:
Enabled:

  • activity: 2.3.8
  • calendar: 1.6.0
  • comments: 0.3.0
  • configreport: 0.1.1
  • contacts: 1.5.4
  • dav: 0.4.0
  • federatedfilesharing: 0.3.1
  • federation: 0.1.0
  • files: 1.5.1
  • files_clipboard: 0.7.1
  • files_external: 0.7.1
  • files_pdfviewer: 0.9.0
  • files_sharing: 0.11.0
  • 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.1.0
  • market: 0.2.5
  • notifications: 0.3.5
  • provisioning_api: 0.5.0
  • systemtags: 0.3.0
  • tasks: 0.9.6
  • updatenotification: 0.2.1
  • user_ldap: 0.11.0
    Disabled:
  • encryption
  • external
  • user_external

Are you using external storage, if yes which one: local (both local and on-local are affected by the bug)

Are you using encryption: no

Are you using an external user-backend, if yes which one: LDAP

LDAP configuration (delete this part if not used)

+-------------------------------+------------------------------------------------------------------------------------------------------+
| Configuration | |
+-------------------------------+------------------------------------------------------------------------------------------------------+
| hasMemberOfFilterSupport | 1 |
| hasPagedResultSupport | |
| homeFolderNamingRule | |
| lastJpegPhotoLookup | 0 |
| ldapAgentName | uid=,dc=,dc=com |
| ldapAgentPassword | *** |
| ldapAttributesForGroupSearch | |
| ldapAttributesForUserSearch | |
| ldapBackupHost | |
| ldapBackupPort | |
| ldapBase | dc=,dc=com |
| ldapBaseGroups | dc=,dc=com |
| ldapBaseUsers | dc=,dc=com |
| ldapCacheTTL | 600 |
| ldapConfigurationActive | 1 |
| ldapDynamicGroupMemberURL | |
| ldapEmailAttribute | mail |
| ldapExperiencedAdmin | 0 |
| ldapExpertUUIDGroupAttr | |
| ldapExpertUUIDUserAttr | |
| ldapExpertUsernameAttr | |
| ldapGroupDisplayName | cn |
| ldapGroupFilter | (&(|(objectclass=posixGroup))(|(cn=))) |
| ldapGroupFilterGroups | app-mssl-owncloud |
| ldapGroupFilterMode | 0 |
| ldapGroupFilterObjectclass | posixGroup |
| ldapGroupMemberAssocAttr | member |
| ldapHost | ldap://localhost |
| ldapIgnoreNamingRules | |
| ldapLoginFilter | (&(&(|(objectclass=posixAccount))(|(memberof=cn=,dc=,dc=com)))(uid=%uid)) |
| ldapLoginFilterAttributes | |
| ldapLoginFilterEmail | 0 |
| ldapLoginFilterMode | 1 |
| ldapLoginFilterUsername | 1 |
| ldapNestedGroups | 0 |
| ldapOverrideMainServer | 0 |
| ldapPagingSize | 500 |
| ldapPort | 389 |
| ldapQuotaAttribute | |
| ldapQuotaDefault | |
| ldapTLS | 0 |
| ldapUserDisplayName | cn |
| ldapUserDisplayName2 | |
| ldapUserFilter | (&(|(objectclass=posixAccount))(|(memberof=cn=*,dc=,dc=com))) |
| ldapUserFilterGroups | ****** |
| ldapUserFilterMode | 0 |
| ldapUserFilterObjectclass | posixAccount |
| ldapUuidGroupAttribute | auto |
| ldapUuidUserAttribute | auto |
| turnOffCertCheck | 0 |
| useMemberOfToDetectMembership | 1 |
+-------------------------------+------------------------------------------------------------------------------------------------------+

Client configuration

Browser:
Firefox 62.0.3 x64
Operating system:
Windows 7 Pro SP1

Logs

Web server error log

[Wed Oct 10 06:28:59.173708 2018] [autoindex:error] [pid 29121] [client 80.0.19.166:50416] AH01276: Cannot serve directory /var/www/owncloud/core/doc/user/_static/: No matching DirectoryIndex (index.php,index.html) found, and server-generated directory index forbidden by Options directive, referer: https://owncloud.mainscreen.com/core/doc/user/index.html
[Wed Oct 10 06:29:27.979988 2018] [authz_core:error] [pid 29123] [client 80.0.19.166:50429] AH01630: client denied by server configuration: /var/www/owncloud/data/htaccesstest.txt
[Wed Oct 10 06:34:52.739802 2018] [authz_core:error] [pid 1921] [client 80.0.19.166:50494] AH01630: client denied by server configuration: /var/www/owncloud/data/htaccesstest.txt

ownCloud log (data/owncloud.log)

{"reqId":"io6js0bigzxWTykDOzgR","level":1,"time":"2018-10-10T00:00:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for local cache"}
{"reqId":"io6js0bigzxWTykDOzgR","level":1,"time":"2018-10-10T00:00:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for distributed cache"}
{"reqId":"io6js0bigzxWTykDOzgR","level":1,"time":"2018-10-10T00:00:13+00:00","remoteAddr":"","user":"--","app":"cron","method":"--","url":"--","message":"Invalidating tokens older than 2018-10-09T00:00:13+00:00"}
{"reqId":"p8UAF26EtbmoTDNEl2Ay","level":1,"time":"2018-10-10T00:15:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for local cache"}
{"reqId":"p8UAF26EtbmoTDNEl2Ay","level":1,"time":"2018-10-10T00:15:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for distributed cache"}
{"reqId":"p8UAF26EtbmoTDNEl2Ay","level":1,"time":"2018-10-10T00:15:03+00:00","remoteAddr":"","user":"--","app":"cron","method":"--","url":"--","message":"Invalidating tokens older than 2018-10-09T00:15:03+00:00"}
{"reqId":"fg5dmV7CvNHXz2NudFyf","level":1,"time":"2018-10-10T00:30:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for local cache"}
{"reqId":"fg5dmV7CvNHXz2NudFyf","level":1,"time":"2018-10-10T00:30:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for distributed cache"}
{"reqId":"fg5dmV7CvNHXz2NudFyf","level":1,"time":"2018-10-10T00:30:03+00:00","remoteAddr":"","user":"--","app":"cron","method":"--","url":"--","message":"Invalidating tokens older than 2018-10-09T00:30:03+00:00"}
{"reqId":"tFGCdBd2OrfQbAWD1clH","level":1,"time":"2018-10-10T00:45:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for local cache"}
{"reqId":"tFGCdBd2OrfQbAWD1clH","level":1,"time":"2018-10-10T00:45:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for distributed cache"}
{"reqId":"tFGCdBd2OrfQbAWD1clH","level":1,"time":"2018-10-10T00:45:02+00:00","remoteAddr":"","user":"--","app":"cron","method":"--","url":"--","message":"Invalidating tokens older than 2018-10-09T00:45:02+00:00"}
{"reqId":"cSTdOhqGGqqNByKnOOSs","level":2,"time":"2018-10-10T00:45:23+00:00","remoteAddr":"198.108.66.176","user":"--","app":"core","method":"GET","url":"/","message":"Trusted domain error. "198.108.66.176" tried to access using "92.48.80.94" as host."}
{"reqId":"3qEM2rPr1h1MaMgk9gXT","level":2,"time":"2018-10-10T00:46:44+00:00","remoteAddr":"162.243.142.140","user":"--","app":"core","method":"GET","url":"/","message":"Trusted domain error. "162.243.142.140" tried to access using "92.48.80.94" as host."}
{"reqId":"YXhdi4txJH4YMBDmVPHY","level":2,"time":"2018-10-10T00:48:51+00:00","remoteAddr":"162.243.142.140","user":"--","app":"core","method":"GET","url":"/","message":"Trusted domain error. "162.243.142.140" tried to access using "92.48.80.91" as host."}
{"reqId":"nZuTZiSJ3MPoV4uWVaDU","level":2,"time":"2018-10-10T00:48:58+00:00","remoteAddr":"162.243.142.140","user":"--","app":"core","method":"GET","url":"/","message":"Trusted domain error. "162.243.142.140" tried to access using "92.48.80.95" as host."}
{"reqId":"waUbHdLehuPcG6kgCgpZ","level":2,"time":"2018-10-10T00:56:18+00:00","remoteAddr":"60.191.38.77","user":"--","app":"core","method":"GET","url":"/","message":"Trusted domain error. "60.191.38.77" tried to access using "92.48.80.94" as host."}
{"reqId":"bVra35Eut1e88mu12I6w","level":1,"time":"2018-10-10T01:00:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for local cache"}
{"reqId":"bVra35Eut1e88mu12I6w","level":1,"time":"2018-10-10T01:00:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for distributed cache"}
{"reqId":"bVra35Eut1e88mu12I6w","level":1,"time":"2018-10-10T01:00:20+00:00","remoteAddr":"","user":"--","app":"cron","method":"--","url":"--","message":"Invalidating tokens older than 2018-10-09T01:00:20+00:00"}
{"reqId":"O41NxDj0uTk2zO75OS81","level":1,"time":"2018-10-10T01:15:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for local cache"}
{"reqId":"O41NxDj0uTk2zO75OS81","level":1,"time":"2018-10-10T01:15:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for distributed cache"}
{"reqId":"O41NxDj0uTk2zO75OS81","level":1,"time":"2018-10-10T01:15:03+00:00","remoteAddr":"","user":"--","app":"cron","method":"--","url":"--","message":"Invalidating tokens older than 2018-10-09T01:15:03+00:00"}
{"reqId":"TXQaRoWSmWV7fIRS12YK","level":1,"time":"2018-10-10T01:30:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for local cache"}
{"reqId":"TXQaRoWSmWV7fIRS12YK","level":1,"time":"2018-10-10T01:30:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for distributed cache"}
{"reqId":"TXQaRoWSmWV7fIRS12YK","level":1,"time":"2018-10-10T01:30:09+00:00","remoteAddr":"","user":"--","app":"cron","method":"--","url":"--","message":"Invalidating tokens older than 2018-10-09T01:30:09+00:00"}
{"reqId":"ytI8s8tWlM5o42vWhinL","level":1,"time":"2018-10-10T01:45:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for local cache"}
{"reqId":"ytI8s8tWlM5o42vWhinL","level":1,"time":"2018-10-10T01:45:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for distributed cache"}
{"reqId":"ytI8s8tWlM5o42vWhinL","level":1,"time":"2018-10-10T01:45:12+00:00","remoteAddr":"","user":"--","app":"cron","method":"--","url":"--","message":"Invalidating tokens older than 2018-10-09T01:45:12+00:00"}
{"reqId":"KJWEt7ssmwi0YCSQsOW3","level":1,"time":"2018-10-10T02:00:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for local cache"}
{"reqId":"KJWEt7ssmwi0YCSQsOW3","level":1,"time":"2018-10-10T02:00:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for distributed cache"}
{"reqId":"KJWEt7ssmwi0YCSQsOW3","level":1,"time":"2018-10-10T02:00:12+00:00","remoteAddr":"","user":"--","app":"cron","method":"--","url":"--","message":"Invalidating tokens older than 2018-10-09T02:00:12+00:00"}
{"reqId":"aofjKUppYMizgD8BGtXt","level":1,"time":"2018-10-10T02:15:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for local cache"}
{"reqId":"aofjKUppYMizgD8BGtXt","level":1,"time":"2018-10-10T02:15:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for distributed cache"}
{"reqId":"aofjKUppYMizgD8BGtXt","level":1,"time":"2018-10-10T02:15:18+00:00","remoteAddr":"","user":"--","app":"cron","method":"--","url":"--","message":"Invalidating tokens older than 2018-10-09T02:15:18+00:00"}
{"reqId":"GyaxHKVwy8yE4FvV3Pth","level":1,"time":"2018-10-10T02:30:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for local cache"}
{"reqId":"GyaxHKVwy8yE4FvV3Pth","level":1,"time":"2018-10-10T02:30:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for distributed cache"}
{"reqId":"GyaxHKVwy8yE4FvV3Pth","level":1,"time":"2018-10-10T02:31:12+00:00","remoteAddr":"","user":"--","app":"cron","method":"--","url":"--","message":"Invalidating tokens older than 2018-10-09T02:31:12+00:00"}
{"reqId":"sA7tVNg7KztliycKCZ56","level":1,"time":"2018-10-10T02:45:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for local cache"}
{"reqId":"sA7tVNg7KztliycKCZ56","level":1,"time":"2018-10-10T02:45:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for distributed cache"}
{"reqId":"sA7tVNg7KztliycKCZ56","level":1,"time":"2018-10-10T02:45:14+00:00","remoteAddr":"","user":"--","app":"cron","method":"--","url":"--","message":"Invalidating tokens older than 2018-10-09T02:45:14+00:00"}
{"reqId":"nS75TexnjR0YWdIJnBow","level":1,"time":"2018-10-10T03:00:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for local cache"}
{"reqId":"nS75TexnjR0YWdIJnBow","level":1,"time":"2018-10-10T03:00:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for distributed cache"}
{"reqId":"nS75TexnjR0YWdIJnBow","level":1,"time":"2018-10-10T03:00:04+00:00","remoteAddr":"","user":"--","app":"cron","method":"--","url":"--","message":"Invalidating tokens older than 2018-10-09T03:00:04+00:00"}
{"reqId":"Ghqra3D07UE0OtymunNK","level":1,"time":"2018-10-10T03:15:02+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for local cache"}
{"reqId":"Ghqra3D07UE0OtymunNK","level":1,"time":"2018-10-10T03:15:02+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for distributed cache"}
{"reqId":"Ghqra3D07UE0OtymunNK","level":1,"time":"2018-10-10T03:15:05+00:00","remoteAddr":"","user":"--","app":"cron","method":"--","url":"--","message":"Invalidating tokens older than 2018-10-09T03:15:05+00:00"}
{"reqId":"F3eq2Xp84nk5PuREEFkJ","level":1,"time":"2018-10-10T03:30:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for local cache"}
{"reqId":"F3eq2Xp84nk5PuREEFkJ","level":1,"time":"2018-10-10T03:30:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for distributed cache"}
{"reqId":"F3eq2Xp84nk5PuREEFkJ","level":1,"time":"2018-10-10T03:30:02+00:00","remoteAddr":"","user":"--","app":"cron","method":"--","url":"--","message":"Invalidating tokens older than 2018-10-09T03:30:02+00:00"}
{"reqId":"bCmHRZDcS10t4nh3SnBf","level":1,"time":"2018-10-10T03:45:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for local cache"}
{"reqId":"bCmHRZDcS10t4nh3SnBf","level":1,"time":"2018-10-10T03:45:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for distributed cache"}
{"reqId":"bCmHRZDcS10t4nh3SnBf","level":1,"time":"2018-10-10T03:45:02+00:00","remoteAddr":"","user":"--","app":"cron","method":"--","url":"--","message":"Invalidating tokens older than 2018-10-09T03:45:02+00:00"}
{"reqId":"AJYKeRL9kKXcUwWippFL","level":2,"time":"2018-10-10T03:49:51+00:00","remoteAddr":"139.162.116.133","user":"--","app":"core","method":"GET","url":"/","message":"Trusted domain error. "139.162.116.133" tried to access using "92.48.80.95" as host."}
{"reqId":"jR0se8ZDiM43R3TClXr0","level":2,"time":"2018-10-10T03:55:21+00:00","remoteAddr":"123.186.223.161","user":"--","app":"core","method":"GET","url":"/","message":"Trusted domain error. "123.186.223.161" tried to access using "92.48.80.94:443" as host."}
{"reqId":"DutqBPrfDl6y3LtvM8oy","level":1,"time":"2018-10-10T04:00:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for local cache"}
{"reqId":"DutqBPrfDl6y3LtvM8oy","level":1,"time":"2018-10-10T04:00:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for distributed cache"}
{"reqId":"DutqBPrfDl6y3LtvM8oy","level":1,"time":"2018-10-10T04:00:03+00:00","remoteAddr":"","user":"--","app":"cron","method":"--","url":"--","message":"Invalidating tokens older than 2018-10-09T04:00:03+00:00"}
{"reqId":"dcbbd189-9a33-4ec2-8f51-3ddb155b307f","level":4,"time":"2018-10-10T04:12:08+00:00","remoteAddr":"80.0.19.166","user":"1f58a300-382a-1032-88a7-719ff25ec74a","app":"webdav","method":"GET","url":"/remote.php/dav/files/1f58a300-382a-1032-88a7-719ff25ec74a/development/TrackingDatabase.dev/DoNotUse.accdb","message":"Exception: HTTP/1.1 423 "development/TrackingDatabase.dev/DoNotUse.accdb" is locked: {"Exception":"OCA\\DAV\\Connector\\Sabre\\Exception\\FileLocked","Message":"\"development\/TrackingDatabase.dev\/DoNotUse.accdb\" is locked","Code":0,"Trace":"#0 \/var\/www\/owncloud\/lib\/composer\/sabre\/dav\/lib\/DAV\/CorePlugin.php(85): OCA\\DAV\\Connector\\Sabre\\File->get()\n#1 [internal function]: Sabre\\DAV\\CorePlugin->httpGet(Object(Sabre\\HTTP\\Request), Object(Sabre\\HTTP\\Response))\n#2 \/var\/www\/owncloud\/lib\/composer\/sabre\/event\/lib\/EventEmitterTrait.php(105): call_user_func_array(Array, Array)\n#3 \/var\/www\/owncloud\/lib\/composer\/sabre\/dav\/lib\/DAV\/Server.php(479): Sabre\\Event\\EventEmitter->emit('method:GET', Array)\n#4 \/var\/www\/owncloud\/lib\/composer\/sabre\/dav\/lib\/DAV\/Server.php(254): Sabre\\DAV\\Server->invokeMethod(Object(Sabre\\HTTP\\Request), Object(Sabre\\HTTP\\Response))\n#5 \/var\/www\/owncloud\/apps\/dav\/lib\/Server.php(298): Sabre\\DAV\\Server->exec()\n#6 \/var\/www\/owncloud\/apps\/dav\/appinfo\/v2\/remote.php(31): OCA\\DAV\\Server->exec()\n#7 \/var\/www\/owncloud\/remote.php(165): require_once('\/var\/www\/ownclo...')\n#8 {main}","File":"\/var\/www\/owncloud\/apps\/dav\/lib\/Connector\/Sabre\/File.php","Line":406}"}
{"reqId":"AqFusOmr4AG6qhdSrwhH","level":1,"time":"2018-10-10T04:15:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for local cache"}
{"reqId":"AqFusOmr4AG6qhdSrwhH","level":1,"time":"2018-10-10T04:15:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for distributed cache"}
{"reqId":"AqFusOmr4AG6qhdSrwhH","level":1,"time":"2018-10-10T04:15:03+00:00","remoteAddr":"","user":"--","app":"cron","method":"--","url":"--","message":"Invalidating tokens older than 2018-10-09T04:15:03+00:00"}
{"reqId":"AqFusOmr4AG6qhdSrwhH","level":3,"time":"2018-10-10T04:16:17+00:00","remoteAddr":"","user":"--","app":"no app in context","method":"--","url":"--","message":"Exception: {"Exception":"OCP\\Files\\NotFoundException","Message":"\/files_trashbin\/files\/CA_TrackingDatabse_be.laccdb.d1539144617 not found while trying to get owner","Code":0,"Trace":"#0 \/var\/www\/owncloud\/lib\/private\/Files\/Filesystem.php(961): OC\\Files\\View->getOwner('\/files_trashbin...')\n#1 \/var\/www\/owncloud\/lib\/private\/Preview.php(1241): OC\\Files\\Filesystem::getOwner('\/files_trashbin...')\n#2 \/var\/www\/owncloud\/lib\/private\/legacy\/hook.php(105): OC\\Preview::prepare_delete(Array)\n#3 \/var\/www\/owncloud\/apps\/files_trashbin\/lib\/Trashbin.php(625): OC_Hook::emit('\\\\OCP\\\\Trashbin', 'preDelete', Array)\n#4 \/var\/www\/owncloud\/apps\/files_trashbin\/lib\/Trashbin.php(664): OCA\\Files_Trashbin\\Trashbin::emitTrashbinPreDelete('\/files_trashbin...')\n#5 \/var\/www\/owncloud\/apps\/files_trashbin\/lib\/Trashbin.php(801): OCA\\Files_Trashbin\\Trashbin::delete('CA_TrackingData...', '1f58a300-382a-1...', '1539144617')\n#6 \/var\/www\/owncloud\/apps\/files_trashbin\/lib\/Trashbin.php(761): OCA\\Files_Trashbin\\Trashbin::deleteFiles(Array, '1f58a300-382a-1...', -9885081809)\n#7 \/var\/www\/owncloud\/apps\/files_trashbin\/lib\/Command\/Expire.php(56): OCA\\Files_Trashbin\\Trashbin::expire('1f58a300-382a-1...')\n#8 \/var\/www\/owncloud\/lib\/private\/Command\/CommandJob.php(34): OCA\\Files_Trashbin\\Command\\Expire->handle()\n#9 \/var\/www\/owncloud\/lib\/private\/BackgroundJob\/Job.php(57): OC\\Command\\CommandJob->run('O:33:\"OCA\\\\Files...')\n#10 \/var\/www\/owncloud\/lib\/private\/BackgroundJob\/QueuedJob.php(42): OC\\BackgroundJob\\Job->execute(Object(OC\\BackgroundJob\\JobList), Object(OC\\Log))\n#11 \/var\/www\/owncloud\/cron.php(120): OC\\BackgroundJob\\QueuedJob->execute(Object(OC\\BackgroundJob\\JobList), Object(OC\\Log))\n#12 {main}","File":"\/var\/www\/owncloud\/lib\/private\/Files\/View.php","Line":1717}"}
{"reqId":"AqFusOmr4AG6qhdSrwhH","level":3,"time":"2018-10-10T04:16:18+00:00","remoteAddr":"","user":"--","app":"no app in context","method":"--","url":"--","message":"Exception: {"Exception":"OCP\\Files\\NotFoundException","Message":"\/files_trashbin\/files\/CA_TrackingDatabse_be.laccdb.d1539144617 not found while trying to get owner","Code":0,"Trace":"#0 \/var\/www\/owncloud\/lib\/private\/Files\/Filesystem.php(961): OC\\Files\\View->getOwner('\/files_trashbin...')\n#1 \/var\/www\/owncloud\/lib\/private\/Preview.php(1311): OC\\Files\\Filesystem::getOwner('\/files_trashbin...')\n#2 \/var\/www\/owncloud\/lib\/private\/legacy\/hook.php(105): OC\\Preview::post_delete(Array)\n#3 \/var\/www\/owncloud\/apps\/files_trashbin\/lib\/Trashbin.php(633): OC_Hook::emit('\\\\OCP\\\\Trashbin', 'delete', Array)\n#4 \/var\/www\/owncloud\/apps\/files_trashbin\/lib\/Trashbin.php(666): OCA\\Files_Trashbin\\Trashbin::emitTrashbinPostDelete('\/files_trashbin...')\n#5 \/var\/www\/owncloud\/apps\/files_trashbin\/lib\/Trashbin.php(801): OCA\\Files_Trashbin\\Trashbin::delete('CA_TrackingData...', '1f58a300-382a-1...', '1539144617')\n#6 \/var\/www\/owncloud\/apps\/files_trashbin\/lib\/Trashbin.php(761): OCA\\Files_Trashbin\\Trashbin::deleteFiles(Array, '1f58a300-382a-1...', -9885081809)\n#7 \/var\/www\/owncloud\/apps\/files_trashbin\/lib\/Command\/Expire.php(56): OCA\\Files_Trashbin\\Trashbin::expire('1f58a300-382a-1...')\n#8 \/var\/www\/owncloud\/lib\/private\/Command\/CommandJob.php(34): OCA\\Files_Trashbin\\Command\\Expire->handle()\n#9 \/var\/www\/owncloud\/lib\/private\/BackgroundJob\/Job.php(57): OC\\Command\\CommandJob->run('O:33:\"OCA\\\\Files...')\n#10 \/var\/www\/owncloud\/lib\/private\/BackgroundJob\/QueuedJob.php(42): OC\\BackgroundJob\\Job->execute(Object(OC\\BackgroundJob\\JobList), Object(OC\\Log))\n#11 \/var\/www\/owncloud\/cron.php(120): OC\\BackgroundJob\\QueuedJob->execute(Object(OC\\BackgroundJob\\JobList), Object(OC\\Log))\n#12 {main}","File":"\/var\/www\/owncloud\/lib\/private\/Files\/View.php","Line":1717}"}
{"reqId":"AqFusOmr4AG6qhdSrwhH","level":1,"time":"2018-10-10T04:16:18+00:00","remoteAddr":"","user":"--","app":"files_trashbin","method":"--","url":"--","message":"remove "CA_TrackingDatabse_be.laccdb" (320B) to meet the limit of trash bin size (50% of available quota)"}
{"reqId":"AqFusOmr4AG6qhdSrwhH","level":1,"time":"2018-10-10T04:16:18+00:00","remoteAddr":"","user":"--","app":"files_versions","method":"--","url":"--","message":"Mark to expire /development/TrackingDatabase.dev/DoNotUse.accdb next version should be 1538579767 or smaller. (prevTimestamp: 1538666167; step: 86400"}
{"reqId":"AqFusOmr4AG6qhdSrwhH","level":1,"time":"2018-10-10T04:16:18+00:00","remoteAddr":"","user":"--","app":"files_versions","method":"--","url":"--","message":"Mark to expire /development/TrackingDatabase.dev/DoNotUse.accdb next version should be 1535735175 or smaller. (prevTimestamp: 1536339975; step: 604800"}
{"reqId":"AqFusOmr4AG6qhdSrwhH","level":3,"time":"2018-10-10T04:16:18+00:00","remoteAddr":"","user":"--","app":"no app in context","method":"--","url":"--","message":"Exception: {"Exception":"OCP\\Files\\NotFoundException","Message":"\/development\/TrackingDatabase.dev\/DoNotUse.accdb.v1538581611 not found while trying to get owner","Code":0,"Trace":"#0 \/var\/www\/owncloud\/lib\/private\/Files\/Filesystem.php(961): OC\\Files\\View->getOwner('\/development\/Tr...')\n#1 \/var\/www\/owncloud\/lib\/private\/Preview.php(1241): OC\\Files\\Filesystem::getOwner('\/development\/Tr...')\n#2 \/var\/www\/owncloud\/lib\/private\/legacy\/hook.php(105): OC\\Preview::prepare_delete(Array)\n#3 \/var\/www\/owncloud\/apps\/files_versions\/lib\/Storage.php(765): OC_Hook::emit('\\\\OCP\\\\Versions', 'preDelete', Array)\n#4 \/var\/www\/owncloud\/apps\/files_versions\/lib\/Command\/Expire.php(60): OCA\\Files_Versions\\Storage::expire('\/development\/Tr...', '1f58a300-382a-1...')\n#5 \/var\/www\/owncloud\/lib\/private\/Command\/CommandJob.php(34): OCA\\Files_Versions\\Command\\Expire->handle()\n#6 \/var\/www\/owncloud\/lib\/private\/BackgroundJob\/Job.php(57): OC\\Command\\CommandJob->run('O:33:\"OCA\\\\Files...')\n#7 \/var\/www\/owncloud\/lib\/private\/BackgroundJob\/QueuedJob.php(42): OC\\BackgroundJob\\Job->execute(Object(OC\\BackgroundJob\\JobList), Object(OC\\Log))\n#8 \/var\/www\/owncloud\/cron.php(120): OC\\BackgroundJob\\QueuedJob->execute(Object(OC\\BackgroundJob\\JobList), Object(OC\\Log))\n#9 {main}","File":"\/var\/www\/owncloud\/lib\/private\/Files\/View.php","Line":1717}"}
{"reqId":"AqFusOmr4AG6qhdSrwhH","level":3,"time":"2018-10-10T04:16:18+00:00","remoteAddr":"","user":"--","app":"no app in context","method":"--","url":"--","message":"Exception: {"Exception":"OCP\\Files\\NotFoundException","Message":"\/development\/TrackingDatabase.dev\/DoNotUse.accdb.v1538581611 not found while trying to get owner","Code":0,"Trace":"#0 \/var\/www\/owncloud\/lib\/private\/Files\/Filesystem.php(961): OC\\Files\\View->getOwner('\/development\/Tr...')\n#1 \/var\/www\/owncloud\/lib\/private\/Preview.php(1311): OC\\Files\\Filesystem::getOwner('\/development\/Tr...')\n#2 \/var\/www\/owncloud\/lib\/private\/Preview.php(1299): OC\\Preview::post_delete(Array, 'files\/')\n#3 \/var\/www\/owncloud\/lib\/private\/legacy\/hook.php(105): OC\\Preview::post_delete_versions(Array)\n#4 \/var\/www\/owncloud\/apps\/files_versions\/lib\/Storage.php(767): OC_Hook::emit('\\\\OCP\\\\Versions', 'delete', Array)\n#5 \/var\/www\/owncloud\/apps\/files_versions\/lib\/Command\/Expire.php(60): OCA\\Files_Versions\\Storage::expire('\/development\/Tr...', '1f58a300-382a-1...')\n#6 \/var\/www\/owncloud\/lib\/private\/Command\/CommandJob.php(34): OCA\\Files_Versions\\Command\\Expire->handle()\n#7 \/var\/www\/owncloud\/lib\/private\/BackgroundJob\/Job.php(57): OC\\Command\\CommandJob->run('O:33:\"OCA\\\\Files...')\n#8 \/var\/www\/owncloud\/lib\/private\/BackgroundJob\/QueuedJob.php(42): OC\\BackgroundJob\\Job->execute(Object(OC\\BackgroundJob\\JobList), Object(OC\\Log))\n#9 \/var\/www\/owncloud\/cron.php(120): OC\\BackgroundJob\\QueuedJob->execute(Object(OC\\BackgroundJob\\JobList), Object(OC\\Log))\n#10 {main}","File":"\/var\/www\/owncloud\/lib\/private\/Files\/View.php","Line":1717}"}
{"reqId":"AqFusOmr4AG6qhdSrwhH","level":1,"time":"2018-10-10T04:16:18+00:00","remoteAddr":"","user":"--","app":"files_versions","method":"--","url":"--","message":"Expire: /development/TrackingDatabase.dev/DoNotUse.accdb.v1538581611"}
{"reqId":"AqFusOmr4AG6qhdSrwhH","level":3,"time":"2018-10-10T04:16:18+00:00","remoteAddr":"","user":"--","app":"no app in context","method":"--","url":"--","message":"Exception: {"Exception":"OCP\\Files\\NotFoundException","Message":"\/development\/TrackingDatabase.dev\/DoNotUse.accdb.v1536229519 not found while trying to get owner","Code":0,"Trace":"#0 \/var\/www\/owncloud\/lib\/private\/Files\/Filesystem.php(961): OC\\Files\\View->getOwner('\/development\/Tr...')\n#1 \/var\/www\/owncloud\/lib\/private\/Preview.php(1241): OC\\Files\\Filesystem::getOwner('\/development\/Tr...')\n#2 \/var\/www\/owncloud\/lib\/private\/legacy\/hook.php(105): OC\\Preview::prepare_delete(Array)\n#3 \/var\/www\/owncloud\/apps\/files_versions\/lib\/Storage.php(765): OC_Hook::emit('\\\\OCP\\\\Versions', 'preDelete', Array)\n#4 \/var\/www\/owncloud\/apps\/files_versions\/lib\/Command\/Expire.php(60): OCA\\Files_Versions\\Storage::expire('\/development\/Tr...', '1f58a300-382a-1...')\n#5 \/var\/www\/owncloud\/lib\/private\/Command\/CommandJob.php(34): OCA\\Files_Versions\\Command\\Expire->handle()\n#6 \/var\/www\/owncloud\/lib\/private\/BackgroundJob\/Job.php(57): OC\\Command\\CommandJob->run('O:33:\"OCA\\\\Files...')\n#7 \/var\/www\/owncloud\/lib\/private\/BackgroundJob\/QueuedJob.php(42): OC\\BackgroundJob\\Job->execute(Object(OC\\BackgroundJob\\JobList), Object(OC\\Log))\n#8 \/var\/www\/owncloud\/cron.php(120): OC\\BackgroundJob\\QueuedJob->execute(Object(OC\\BackgroundJob\\JobList), Object(OC\\Log))\n#9 {main}","File":"\/var\/www\/owncloud\/lib\/private\/Files\/View.php","Line":1717}"}
{"reqId":"AqFusOmr4AG6qhdSrwhH","level":3,"time":"2018-10-10T04:16:19+00:00","remoteAddr":"","user":"--","app":"no app in context","method":"--","url":"--","message":"Exception: {"Exception":"OCP\\Files\\NotFoundException","Message":"\/development\/TrackingDatabase.dev\/DoNotUse.accdb.v1536229519 not found while trying to get owner","Code":0,"Trace":"#0 \/var\/www\/owncloud\/lib\/private\/Files\/Filesystem.php(961): OC\\Files\\View->getOwner('\/development\/Tr...')\n#1 \/var\/www\/owncloud\/lib\/private\/Preview.php(1311): OC\\Files\\Filesystem::getOwner('\/development\/Tr...')\n#2 \/var\/www\/owncloud\/lib\/private\/Preview.php(1299): OC\\Preview::post_delete(Array, 'files\/')\n#3 \/var\/www\/owncloud\/lib\/private\/legacy\/hook.php(105): OC\\Preview::post_delete_versions(Array)\n#4 \/var\/www\/owncloud\/apps\/files_versions\/lib\/Storage.php(767): OC_Hook::emit('\\\\OCP\\\\Versions', 'delete', Array)\n#5 \/var\/www\/owncloud\/apps\/files_versions\/lib\/Command\/Expire.php(60): OCA\\Files_Versions\\Storage::expire('\/development\/Tr...', '1f58a300-382a-1...')\n#6 \/var\/www\/owncloud\/lib\/private\/Command\/CommandJob.php(34): OCA\\Files_Versions\\Command\\Expire->handle()\n#7 \/var\/www\/owncloud\/lib\/private\/BackgroundJob\/Job.php(57): OC\\Command\\CommandJob->run('O:33:\"OCA\\\\Files...')\n#8 \/var\/www\/owncloud\/lib\/private\/BackgroundJob\/QueuedJob.php(42): OC\\BackgroundJob\\Job->execute(Object(OC\\BackgroundJob\\JobList), Object(OC\\Log))\n#9 \/var\/www\/owncloud\/cron.php(120): OC\\BackgroundJob\\QueuedJob->execute(Object(OC\\BackgroundJob\\JobList), Object(OC\\Log))\n#10 {main}","File":"\/var\/www\/owncloud\/lib\/private\/Files\/View.php","Line":1717}"}
{"reqId":"AqFusOmr4AG6qhdSrwhH","level":1,"time":"2018-10-10T04:16:19+00:00","remoteAddr":"","user":"--","app":"files_versions","method":"--","url":"--","message":"Expire: /development/TrackingDatabase.dev/DoNotUse.accdb.v1536229519"}
{"reqId":"tDlAZ4nh9GDgrn6JFJuy","level":1,"time":"2018-10-10T04:30:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for local cache"}
{"reqId":"tDlAZ4nh9GDgrn6JFJuy","level":1,"time":"2018-10-10T04:30:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for distributed cache"}
{"reqId":"tDlAZ4nh9GDgrn6JFJuy","level":1,"time":"2018-10-10T04:30:12+00:00","remoteAddr":"","user":"--","app":"cron","method":"--","url":"--","message":"Invalidating tokens older than 2018-10-09T04:30:12+00:00"}
{"reqId":"aRgX5Es5kuwIP5MM6qBY","level":1,"time":"2018-10-10T04:45:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for local cache"}
{"reqId":"aRgX5Es5kuwIP5MM6qBY","level":1,"time":"2018-10-10T04:45:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for distributed cache"}
{"reqId":"aRgX5Es5kuwIP5MM6qBY","level":1,"time":"2018-10-10T04:45:02+00:00","remoteAddr":"","user":"--","app":"cron","method":"--","url":"--","message":"Invalidating tokens older than 2018-10-09T04:45:02+00:00"}
{"reqId":"oDNSQbWFpFhFuADYvexl","level":1,"time":"2018-10-10T05:00:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for local cache"}
{"reqId":"oDNSQbWFpFhFuADYvexl","level":1,"time":"2018-10-10T05:00:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for distributed cache"}
{"reqId":"oDNSQbWFpFhFuADYvexl","level":1,"time":"2018-10-10T05:00:05+00:00","remoteAddr":"","user":"--","app":"cron","method":"--","url":"--","message":"Invalidating tokens older than 2018-10-09T05:00:05+00:00"}
{"reqId":"oDNSQbWFpFhFuADYvexl","level":3,"time":"2018-10-10T05:00:20+00:00","remoteAddr":"","user":"--","app":"no app in context","method":"--","url":"--","message":"Exception: {"Exception":"OCP\\Files\\NotFoundException","Message":"\/files_trashbin\/files\/DoNotUse.accdb.d1539147059 not found while trying to get owner","Code":0,"Trace":"#0 \/var\/www\/owncloud\/lib\/private\/Files\/Filesystem.php(961): OC\\Files\\View->getOwner('\/files_trashbin...')\n#1 \/var\/www\/owncloud\/lib\/private\/Preview.php(1241): OC\\Files\\Filesystem::getOwner('\/files_trashbin...')\n#2 \/var\/www\/owncloud\/lib\/private\/legacy\/hook.php(105): OC\\Preview::prepare_delete(Array)\n#3 \/var\/www\/owncloud\/apps\/files_trashbin\/lib\/Trashbin.php(625): OC_Hook::emit('\\\\OCP\\\\Trashbin', 'preDelete', Array)\n#4 \/var\/www\/owncloud\/apps\/files_trashbin\/lib\/Trashbin.php(664): OCA\\Files_Trashbin\\Trashbin::emitTrashbinPreDelete('\/files_trashbin...')\n#5 \/var\/www\/owncloud\/apps\/files_trashbin\/lib\/Trashbin.php(801): OCA\\Files_Trashbin\\Trashbin::delete('DoNotUse.accdb', '1f58a300-382a-1...', '1539147059')\n#6 \/var\/www\/owncloud\/apps\/files_trashbin\/lib\/Trashbin.php(761): OCA\\Files_Trashbin\\Trashbin::deleteFiles(Array, '1f58a300-382a-1...', -10126847889)\n#7 \/var\/www\/owncloud\/apps\/files_trashbin\/lib\/Command\/Expire.php(56): OCA\\Files_Trashbin\\Trashbin::expire('1f58a300-382a-1...')\n#8 \/var\/www\/owncloud\/lib\/private\/Command\/CommandJob.php(34): OCA\\Files_Trashbin\\Command\\Expire->handle()\n#9 \/var\/www\/owncloud\/lib\/private\/BackgroundJob\/Job.php(57): OC\\Command\\CommandJob->run('O:33:\"OCA\\\\Files...')\n#10 \/var\/www\/owncloud\/lib\/private\/BackgroundJob\/QueuedJob.php(42): OC\\BackgroundJob\\Job->execute(Object(OC\\BackgroundJob\\JobList), Object(OC\\Log))\n#11 \/var\/www\/owncloud\/cron.php(120): OC\\BackgroundJob\\QueuedJob->execute(Object(OC\\BackgroundJob\\JobList), Object(OC\\Log))\n#12 {main}","File":"\/var\/www\/owncloud\/lib\/private\/Files\/View.php","Line":1717}"}
{"reqId":"oDNSQbWFpFhFuADYvexl","level":3,"time":"2018-10-10T05:00:21+00:00","remoteAddr":"","user":"--","app":"no app in context","method":"--","url":"--","message":"Exception: {"Exception":"OCP\\Files\\NotFoundException","Message":"\/files_trashbin\/files\/DoNotUse.accdb.d1539147059 not found while trying to get owner","Code":0,"Trace":"#0 \/var\/www\/owncloud\/lib\/private\/Files\/Filesystem.php(961): OC\\Files\\View->getOwner('\/files_trashbin...')\n#1 \/var\/www\/owncloud\/lib\/private\/Preview.php(1311): OC\\Files\\Filesystem::getOwner('\/files_trashbin...')\n#2 \/var\/www\/owncloud\/lib\/private\/legacy\/hook.php(105): OC\\Preview::post_delete(Array)\n#3 \/var\/www\/owncloud\/apps\/files_trashbin\/lib\/Trashbin.php(633): OC_Hook::emit('\\\\OCP\\\\Trashbin', 'delete', Array)\n#4 \/var\/www\/owncloud\/apps\/files_trashbin\/lib\/Trashbin.php(666): OCA\\Files_Trashbin\\Trashbin::emitTrashbinPostDelete('\/files_trashbin...')\n#5 \/var\/www\/owncloud\/apps\/files_trashbin\/lib\/Trashbin.php(801): OCA\\Files_Trashbin\\Trashbin::delete('DoNotUse.accdb', '1f58a300-382a-1...', '1539147059')\n#6 \/var\/www\/owncloud\/apps\/files_trashbin\/lib\/Trashbin.php(761): OCA\\Files_Trashbin\\Trashbin::deleteFiles(Array, '1f58a300-382a-1...', -10126847889)\n#7 \/var\/www\/owncloud\/apps\/files_trashbin\/lib\/Command\/Expire.php(56): OCA\\Files_Trashbin\\Trashbin::expire('1f58a300-382a-1...')\n#8 \/var\/www\/owncloud\/lib\/private\/Command\/CommandJob.php(34): OCA\\Files_Trashbin\\Command\\Expire->handle()\n#9 \/var\/www\/owncloud\/lib\/private\/BackgroundJob\/Job.php(57): OC\\Command\\CommandJob->run('O:33:\"OCA\\\\Files...')\n#10 \/var\/www\/owncloud\/lib\/private\/BackgroundJob\/QueuedJob.php(42): OC\\BackgroundJob\\Job->execute(Object(OC\\BackgroundJob\\JobList), Object(OC\\Log))\n#11 \/var\/www\/owncloud\/cron.php(120): OC\\BackgroundJob\\QueuedJob->execute(Object(OC\\BackgroundJob\\JobList), Object(OC\\Log))\n#12 {main}","File":"\/var\/www\/owncloud\/lib\/private\/Files\/View.php","Line":1717}"}
{"reqId":"oDNSQbWFpFhFuADYvexl","level":1,"time":"2018-10-10T05:00:21+00:00","remoteAddr":"","user":"--","app":"files_trashbin","method":"--","url":"--","message":"remove "DoNotUse.accdb" (298074112B) to meet the limit of trash bin size (50% of available quota)"}
{"reqId":"Th2Un2tQPYrbjqPpIzyr","level":1,"time":"2018-10-10T05:15:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for local cache"}
{"reqId":"Th2Un2tQPYrbjqPpIzyr","level":1,"time":"2018-10-10T05:15:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for distributed cache"}
{"reqId":"Th2Un2tQPYrbjqPpIzyr","level":1,"time":"2018-10-10T05:15:02+00:00","remoteAddr":"","user":"--","app":"cron","method":"--","url":"--","message":"Invalidating tokens older than 2018-10-09T05:15:02+00:00"}
{"reqId":"DCogqKRhmeczK0JvZRTt","level":2,"time":"2018-10-10T05:29:17+00:00","remoteAddr":"80.0.19.166","user":"1f58a300-382a-1032-88a7-719ff25ec74a","app":"OCA\User_LDAP\User\Manager","method":"GET","url":"/index.php/settings/personal","message":"No cached ldap result found for 1f58a300-382a-1032-88a7-719ff25ec74a"}
{"reqId":"3qw33bbiTe1mLxzcD74Z","level":1,"time":"2018-10-10T05:30:02+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for local cache"}
{"reqId":"3qw33bbiTe1mLxzcD74Z","level":1,"time":"2018-10-10T05:30:02+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for distributed cache"}
{"reqId":"3qw33bbiTe1mLxzcD74Z","level":1,"time":"2018-10-10T05:30:07+00:00","remoteAddr":"","user":"--","app":"cron","method":"--","url":"--","message":"Invalidating tokens older than 2018-10-09T05:30:07+00:00"}
{"reqId":"QXmzvYHxbg4bdJKLVb11","level":2,"time":"2018-10-10T05:32:21+00:00","remoteAddr":"139.162.78.135","user":"--","app":"core","method":"GET","url":"/","message":"Trusted domain error. "139.162.78.135" tried to access using "92.48.80.91" as host."}
{"reqId":"1EpLh3Lmh5gCoaYfI01Y","level":1,"time":"2018-10-10T05:32:56+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for local cache"}
{"reqId":"1EpLh3Lmh5gCoaYfI01Y","level":1,"time":"2018-10-10T05:32:56+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for distributed cache"}
{"reqId":"Poq3qqJYkhWyE06h7Tyr","level":1,"time":"2018-10-10T05:34:33+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for local cache"}
{"reqId":"Poq3qqJYkhWyE06h7Tyr","level":1,"time":"2018-10-10T05:34:33+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for distributed cache"}
{"reqId":"3ol9OrimF0uCPXsyFcHQ","level":1,"time":"2018-10-10T05:37:02+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for local cache"}
{"reqId":"3ol9OrimF0uCPXsyFcHQ","level":1,"time":"2018-10-10T05:37:02+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for distributed cache"}
{"reqId":"vTOj1x3LaTofu4GFR3HG","level":1,"time":"2018-10-10T05:37:43+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for local cache"}
{"reqId":"vTOj1x3LaTofu4GFR3HG","level":1,"time":"2018-10-10T05:37:43+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for distributed cache"}
{"reqId":"nv5n7VKCBlhTyTvQyAbu","level":1,"time":"2018-10-10T05:38:34+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for local cache"}
{"reqId":"nv5n7VKCBlhTyTvQyAbu","level":1,"time":"2018-10-10T05:38:34+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for distributed cache"}
{"reqId":"kUOwN3DzPOo75FbvJnPM","level":1,"time":"2018-10-10T05:39:20+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for local cache"}
{"reqId":"kUOwN3DzPOo75FbvJnPM","level":1,"time":"2018-10-10T05:39:20+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for distributed cache"}
{"reqId":"kUOwN3DzPOo75FbvJnPM","level":3,"time":"2018-10-10T05:39:23+00:00","remoteAddr":"","user":"--","app":"PHP","method":"--","url":"--","message":"copy(/var/www/owncloud/.htaccess): failed to open stream: No such file or directory at /var/www/owncloud/lib/private/IntegrityCheck/Checker.php#188"}
{"reqId":"ZUGhw0i1MdCWi7pS4Soa","level":1,"time":"2018-10-10T05:40:36+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for local cache"}
{"reqId":"ZUGhw0i1MdCWi7pS4Soa","level":1,"time":"2018-10-10T05:40:36+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for distributed cache"}
{"reqId":"SQkhm5vEnrWd2SIojYos","level":1,"time":"2018-10-10T05:41:42+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for local cache"}
{"reqId":"SQkhm5vEnrWd2SIojYos","level":1,"time":"2018-10-10T05:41:42+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for distributed cache"}
{"reqId":"VU6MjRHmdVSfcyvhx4Vy","level":1,"time":"2018-10-10T05:44:51+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for local cache"}
{"reqId":"VU6MjRHmdVSfcyvhx4Vy","level":1,"time":"2018-10-10T05:44:51+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for distributed cache"}
{"reqId":"bJe0KC5PgcKSTLLaAMk7","level":1,"time":"2018-10-10T05:45:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for local cache"}
{"reqId":"bJe0KC5PgcKSTLLaAMk7","level":1,"time":"2018-10-10T05:45:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for distributed cache"}
{"reqId":"bJe0KC5PgcKSTLLaAMk7","level":1,"time":"2018-10-10T05:45:02+00:00","remoteAddr":"","user":"--","app":"cron","method":"--","url":"--","message":"Invalidating tokens older than 2018-10-09T05:45:02+00:00"}
{"reqId":"RCLBxXdvH1rS24KkTDZh","level":1,"time":"2018-10-10T05:45:38+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for local cache"}
{"reqId":"RCLBxXdvH1rS24KkTDZh","level":1,"time":"2018-10-10T05:45:38+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for distributed cache"}
{"reqId":"yxVDhr1q69cyi2a4QVWw","level":1,"time":"2018-10-10T05:47:22+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for local cache"}
{"reqId":"yxVDhr1q69cyi2a4QVWw","level":1,"time":"2018-10-10T05:47:22+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for distributed cache"}
{"reqId":"Lqp8LYGBQk2MBeb0cfbq","level":1,"time":"2018-10-10T06:00:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for local cache"}
{"reqId":"Lqp8LYGBQk2MBeb0cfbq","level":1,"time":"2018-10-10T06:00:01+00:00","remoteAddr":"","user":"--","app":"cli","method":"--","url":"--","message":"Memcache \OC\Memcache\APCu not available for distributed cache"}
{"reqId":"Lqp8LYGBQk2MBeb0cfbq","level":1,"time":"2018-10-10T06:00:02+00:00","remoteAddr":"","user":"--","app":"cron","method":"--","url":"--","message":"Invalidating tokens older than 2018-10-09T06:00:02+00:00"}

Browser log

n/a
@ownclouders
Copy link
Contributor

GitMate.io thinks the contributors most likely able to help are @ownclouders, and @PVince81.

Possibly related issues are #32207 ("403 Forbidden" to "Move"), #23532 (403 Forbidden when DELETE file), #3187 (Sync problem with over-limit-size files), #8103 (Move File), and #481 (moving files).

@PVince81
Copy link
Contributor

can you try uploading a big file (11+ mb) in the web UI and see if you get the same error ?

this could confirm whether it's an issue with the client or server env.

it looks like the prefix part is missing in the "Destination" header of the MOVE, it should start with "https://owncloud.mainscreen.com/remote.php" instead of "//remote.php" and I'm not sure yet who is buildling this URL

@sgparry
Copy link
Author

sgparry commented Oct 11, 2018

@PVince81 - Uploaded a file to the server via web to native owncloud storage; it went up fine. It then synced down fine via client. However, when I tried uploading a new version of the file via the web, or uploading it to local storage, although it uploaded OK it failed to sync back down (red x), throwing the following error in the client:
ownCloud,No E-Tag received from server, check Proxy/Gateway

@PVince81
Copy link
Contributor

it sounds like something is messed up in your environment.
do you have a proxy / reverse proxy ?

did you check http://central.owncloud.org/ for similar issues ?

@sgparry
Copy link
Author

sgparry commented Oct 12, 2018 via email

@sgparry
Copy link
Author

sgparry commented Oct 14, 2018

@PVince81 - I have done some more testing and the following seems to be true: I modify files at home on my own computers, running both Windows and Linux. I also modify files both at home and at work on my work laptop. My home computers run either Kasperky Total Security in Redmondland or nothing in Linusland. My work laptop runs Bitdefender locally and Sophos appliance at the gateway when at on site. I am not sure what it uses when I connect to my home LAN.
If I modify a copy of a file on one of my home computers it syncs the changes up to the server fine. If I modify a copy of the same file on my work laptop I get the weird errors. Sometimes I get the ETAG, sometimes I get the 403. I have not yet been able to confirm which I get under what circumstances, but they seem to be interactions with the security set up on the laptop. Off the network, we get errors even though the proxy setting is 'direct'. Can you please help me locate the cause and any possible solution(s)? I am very keen to get this sorted so that I can propse OC as the correct sync solution for our college.

@PVince81
Copy link
Contributor

as this is a bug tracker it's not the right place to look for support for environment troubles

see https://owncloud.org/support

@sgparry
Copy link
Author

sgparry commented Oct 15, 2018

No, valid point, I will pursue this further there. I may also have a look at the source code to see if I can work out where the conflict is occurring. Thanks for the help so far all the same.

@danielmarschall
Copy link

danielmarschall commented Oct 27, 2018 •
edited

I have exactly the same problem. My client is a Windows system. The server is a Debian 9 with OwnCloud 10.0.10-1+1.1. PHP 7.0.30-0+deb9u1 is running with FCGI/SuExec (with fcgi-wrapper) on an Apache2, no proxy or other stuff. Did you find any solution?

PS: I do think it is a bug... I am using OwnCloud since version 8 and rarely had problems. And after updating to OwnCloud 10, this problem started immediately. And the time is very close to the time @sgparry reported the same problem.

@sgparry
Copy link
Author

sgparry commented Oct 27, 2018 via email

@danielmarschall
Copy link

I do remember an OwnCloud bug from the past (I forgot which it was) that had to do with timing. There was a racecondition that happened when an upload took some time (e.g. when you upload a large file over a slow internet connection). Is it possible that the issue happens on some computers/networks because they have a slow network/internet connection?

@danielmarschall
Copy link

danielmarschall commented Oct 27, 2018 •
edited

Looking in the Apache Access Log, I found some interesting things:

A normal file transfer looks like this:

xxx.xxx.xxx.xxx (xxx.xxx.xxx.xxx) - - [27/Oct/2018:20:50:25 +0200] "PUT /remote.php/dav/files/foobar/Downloads/Altern.png HTTP/1.1" 201 - "-" "Mozilla/5.0 (Windows) mirall/2.5.0 (build 10560)" 5 cloud.example.com

A buggy/failed transfer looks like this:

xxx.xxx.xxx.xxx (xxx.xxx.xxx.xxx) - - [27/Oct/2018:11:13:34 +0200] "MKCOL /remote.php/dav/uploads/foobar/557782415 HTTP/1.1" 201 - "-" "Mozilla/5.0 (Windows) mirall/2.5.0 (build 10560)" 0 cloud.example.com
xxx.xxx.xxx.xxx (xxx.xxx.xxx.xxx) - - [27/Oct/2018:11:13:34 +0200] "PUT /remote.php/dav/uploads/foobar/557782415/00000000 HTTP/1.1" 201 - "-" "Mozilla/5.0 (Windows) mirall/2.5.0 (build 10560)" 50 cloud.example.com
xxx.xxx.xxx.xxx (xxx.xxx.xxx.xxx) - - [27/Oct/2018:11:14:24 +0200] "PUT /remote.php/dav/uploads/foobar/557782415/00000001 HTTP/1.1" 201 - "-" "Mozilla/5.0 (Windows) mirall/2.5.0 (build 10560)" 56 cloud.example.com
xxx.xxx.xxx.xxx (xxx.xxx.xxx.xxx) - - [27/Oct/2018:11:15:20 +0200] "PUT /remote.php/dav/uploads/foobar/557782415/00000002 HTTP/1.1" 201 - "-" "Mozilla/5.0 (Windows) mirall/2.5.0 (build 10560)" 57 cloud.example.com
xxx.xxx.xxx.xxx (xxx.xxx.xxx.xxx) - - [27/Oct/2018:11:16:18 +0200] "PUT /remote.php/dav/uploads/foobar/557782415/00000003 HTTP/1.1" 201 - "-" "Mozilla/5.0 (Windows) mirall/2.5.0 (build 10560)" 15 cloud.example.com
xxx.xxx.xxx.xxx (xxx.xxx.xxx.xxx) - - [27/Oct/2018:11:16:33 +0200] "MOVE /remote.php/dav/uploads/foobar/557782415/.file HTTP/1.1" 201 - "-" "Mozilla/5.0 (Windows) mirall/2.5.0 (build 10560)" 1 cloud.example.com

It seems like large files get split into 11 MB chunks and then there seems to be some kind of bug which triggers the security check violation in the sabre lib ( https://github.com/sabre-io/dav/blob/master/lib/DAV/Server.php#L568 ). It looks like there is just a removal of a double-slash at the beginning missing. But I am not sure if other things went wrong before that.

Question: Is the filename ".file" normal, or a malfunction (i.e. filename not found)?

Note, that in the directories /var/www/owncloud/data/foobar/uploads/*/ there are the chunk files (00000001), but no file is called ".file".

@sgparry
Copy link
Author

sgparry commented Oct 27, 2018 via email

@sgparry
Copy link
Author

sgparry commented Oct 27, 2018 via email

@danielmarschall
Copy link

From home via IPv4, a normal DSL connection (DSL6000) with approx 200 KB/s upload.
Nothing fancy, no additional firewalls.

@danielmarschall
Copy link

danielmarschall commented Oct 27, 2018 •
edited

Related to owncloud/guests#198 ? There, a Sabre Forbidden-Exception (403) happened everytime a chunked transfer happened (= filesize larger than 10 MB).

@danielmarschall
Copy link

danielmarschall commented Oct 28, 2018 •
edited

Since the Exception is thrown in /var/www/owncloud/lib/composer/sabre/dav/lib/DAV/Server.php:calculateUri() , I have added a few debug outputs to check which value the parameter $uri has.

During an upload of a small file (no chunks), the function is called like this:

calculateUri(/remote.php/dav/files/username/filename.txt)
which is called by getRequestUri()

But if a large file was uploaded (chunked upload), the call is like this:

calculateUri(///remote.php/dav/files/username/filename.txt)
which is called by getCopyAndMoveInfo()

There are three slashes at the beginning! But the function calculateUri() only tolerates two slashes (there is a str_replace which converts // to /). So due to the str_replace, /// becomes // , which is still wrong.

The value with the three slashes comes from the HTTP-Header Destination which is sent with the MOVE request. So, in my example, the Destination header has the value "///remote.php/dav/files/username/filename.txt".

I understand that the MOVE HTTP Request is sent by the OwnCloud client. So I guess there is a bug in the Windows client! Or the bug is that three slashes are not tolerated at server side.

@phil-davis phil-davis mentioned this issue Oct 28, 2018
Merged
@phil-davis
Copy link
Contributor

Does a change like this help?
sabre-io/dav#1111

If so, and others think it is an OK thing to do in the server-side, it could be ported back to an appropriate sabre/DAV version.

@danielmarschall
Copy link

It works! That you very much :-)
I recommend this change to be included server-side.

@michaelstingl
Copy link

Is this related?

You could verify with the 2.5.1-daily builds:
https://download.owncloud.com/desktop/daily/?C=M;O=D

@danielmarschall
Copy link

danielmarschall commented Oct 28, 2018 •
edited

Yes, I am very confident that this is the bug in the client that causes the three slashes in front of the Destination-HTTP-Header. In my Windows client, I had set the URI to https://cloud.example.com/ . I think if I would remove the slash at the end of the domain, it should work, too. But I haven't tested it because it would mean to download and upload several gigabytes of data to test it, and I would need to undo my fix on server-side.

I think fixing both (client and server) would be perfect. Personally, I would give the fix at server-side higher priority.

@michaelstingl
Copy link

@dracenmarx As discussed in owncloud/client#6824, removing the slash manually in the owncloud.cfg should also help without the need to re-download everything.

@michaelstingl
Copy link

Client was behaving wrong, but it got fixed. Server-side will be improved with the update of the Sabre component. (sabre-io/dav#1111)

@koying koying mentioned this issue Jun 7, 2019
Closed
@lock lock bot locked as resolved and limited conversation to collaborators Nov 29, 2019
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
6 participants
@michaelstingl @PVince81 @phil-davis @sgparry @danielmarschall @ownclouders