[8.2.2] Cron job creates error #22450

Closed
cdamken opened this Issue Feb 16, 2016 · 71 comments

Projects

None yet

6 participants

@cdamken
Contributor
cdamken commented Feb 16, 2016

I obtain the following erros every time the cron job runs (15 Minutes)

  • for each user the following error:
{"reqId":"p1V8PVOKpDOUNU8teqUv","remoteAddr":"","app":"PHP","message":"opendir(\/mnt\/owncloud\/data\/USERNAME\/files_trashbin\/files): failed to open dir: No such file or directory at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#96","level":3,"time":"2016-02-16T18:30:04+01:00","method":"--","url":"--"}
  • then another error comes:
{"reqId":"p1V8PVOKpDOUNU8teqUv","remoteAddr":"","app":"PHP","message":"filesize(): stat failed for \/mnt\/owncloud\/data\/carlos\/files_versions\/rsions\/hello carlos.txt.v1444125868 at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#139","level":3,"time":"2016-02-16T18:30:05+01:00","method":"--","url":"--"}

This file should be already removed, because the retention oblation is older than 3 months:

-rw-r--r--  1 www-data www-data   117 Okt  6 12:16 hello carlos.txt.v1444125868

and the path has an error: \/rsions\/

Server stack:

• Operating system (name and version number):

Ubuntu 14.04.3 LTS

• URL from your ownCloud
https://cloud.damken.com/

• Your ownCloud availability:
over internet

• Webserver (name and version number):

Server version: Apache/2.4.7 (Ubuntu)
Server built:   Oct 14 2015 14:20:21

• Apache modules enabled as declared in:

access_compat.load
auth_basic.load
authz_core.load
autoindex.conf
deflate.load
env.load
mime.conf
mpm_prefork.load
php5.conf
setenvif.conf
ssl.conf
status.load
alias.conf
authn_core.load
authz_host.load
autoindex.load
dir.conf
filter.load
mime.load
negotiation.conf
php5.load
setenvif.load
ssl.load
alias.load
authn_file.load
authz_user.load
deflate.conf
dir.load
headers.load
mpm_prefork.conf
negotiation.load
rewrite.load
socache_shmcb.load
status.conf

• Database (name and version number):

mysql  Ver 15.1 Distrib 5.5.46-MariaDB, for debian-linux-gnu (x86_64) using readline 5.2

Connection id:          578875
Current database:
Current user:           root@localhost
SSL:                    Not in use
Current pager:          stdout
Using outfile:          ''
Using delimiter:        ;
Server:                 MariaDB
Server version:         5.5.46-MariaDB-1ubuntu0.14.04.2 (Ubuntu)
Protocol version:       10
Connection:             Localhost via UNIX socket
Server characterset:    latin1
Db     characterset:    latin1
Client characterset:    utf8
Conn.  characterset:    utf8
UNIX socket:            /var/run/mysqld/mysqld.sock
Uptime:                 22 days 7 hours 3 min 20 sec

Threads: 2  Questions: 176832246  Slow queries: 1  Opens: 159  Flush tables: 2  Open tables: 122  Queries per second avg: 91.803
--------------

• PHP (version number):

PHP 5.5.9-1ubuntu4.14 (cli) (built: Oct 28 2015 01:34:46)
Copyright (c) 1997-2014 The PHP Group
Zend Engine v2.5.0, Copyright (c) 1998-2014 Zend Technologies
    with Zend OPcache v7.0.3, Copyright (c) 1999-2014, by Zend Technologies

• PHP cache manager

Package: redis-server
Status: install ok installed
Priority: optional
Section: database
Installed-Size: 744
Maintainer: Ubuntu Developers <ubuntu-devel-discuss@lists.ubuntu.com>
Architecture: amd64
Source: redis
Version: 2:2.8.4-2
Depends: libc6 (>= 2.14), libjemalloc1 (>= 2.1.1), redis-tools (= 2:2.8.4-2), adduser
Conffiles:
 /etc/default/redis-server 45e997df22f4c5c2b5c9ae159775a089
 /etc/redis/redis.conf e79ac99a5236e6ab3faf86bdd99affaf
 /etc/redis/sentinel.conf a95ae9b0242a03c5b4dd1af934478895
 /etc/init.d/redis-server 387b03762e0cf0db194e961104137b5a
 /etc/logrotate.d/redis-server 06755b99ef70d62a56cff94cbfc36de7
Description: Persistent key-value database with network interface
 Redis is a key-value database in a similar vein to memcache but the dataset
 is non-volatile. Redis additionally provides native support for atomically
 manipulating and querying data structures such as lists and sets.
 .
 The dataset is stored entirely in memory and periodically flushed to disk.
Original-Maintainer: Chris Lamb <lamby@debian.org>
Homepage: http://redis.io/

• PHP installed packages

libapache2-mod-php5 -> 5.5.9+dfsg-1ubuntu4.14
php-gettext -> 1.0.11-1
php-pear -> 5.5.9+dfsg-1ubuntu4.14
php5 -> 5.5.9+dfsg-1ubuntu4.14
php5-apcu -> 4.0.7-1build1~ubuntu14.04.1
php5-cgi -> 5.5.9+dfsg-1ubuntu4.14
php5-cli -> 5.5.9+dfsg-1ubuntu4.14
php5-common -> 5.5.9+dfsg-1ubuntu4.14
php5-curl -> 5.5.9+dfsg-1ubuntu4.14
php5-dev -> 5.5.9+dfsg-1ubuntu4.14
php5-gd -> 5.5.9+dfsg-1ubuntu4.14
php5-imagick -> 3.1.2-1build1
php5-intl -> 5.5.9+dfsg-1ubuntu4.14
php5-json -> 1.3.2-2build1
php5-libsmbclient -> 0.5.0-10.1
php5-mcrypt -> 5.4.6-0ubuntu5
php5-mysql -> 5.5.9+dfsg-1ubuntu4.14
php5-readline -> 5.5.9+dfsg-1ubuntu4.14
phpmyadmin -> 4:4.0.10-1
pkg-php-tools -> 1.11

• ownCloud Enterprise Server Version

{"installed":true,"maintenance":false,"version":"8.2.2.2","versionstring":"8.2.2","edition":""}

• Did you install your ownCloud with TAR files or packages?
TAR

• Tell us your migration path of the ownCloud software
8.1.0.8 -> 8.1.3.0 -> 8.1.4 -> 8.2.2

• Do you have records from your migration steps?
No

• List of owncloud-apps enabled/ in use:

Enabled:
  - activity: 2.1.3
  - bookmarks: 0.6
  - calendar: 0.8.1
  - contacts: 0.5.0.0
  - delete_confirmation: 1.1.0
  - direct_menu: 0.5
  - documents: 0.11.0
  - files: 1.2.0
  - files_external: 0.3.0
  - files_mv: 0.8.1a
  - files_pdfviewer: 0.7
  - files_sharing: 0.7.0
  - files_texteditor: 2.0
  - files_trashbin: 0.7.0
  - files_versions: 1.1.0
  - firstrunwizard: 1.1
  - gallery: 14.2.0
  - notifications: 0.1.0
  - ownnote: 1.05
  - provisioning_api: 0.3.0
  - registration: 0.1.0
  - sharelinks: 1.0.1
  - tasks: 0.8.1
  - templateeditor: 0.1
  - updater: 0.6

• The content of your config/config.php:

<?php
$CONFIG = array (
  'instanceid' => 'XXXXXX',
  'passwordsalt' => 'XXXXXX',
  'secret' => 'XXXXXX',
  'trusted_domains' =>
  array (
    0 => 'cloud.damken.com',
  ),
  'datadirectory' => '/mnt/owncloud/data',
  'dbtype' => 'mysql',
  'version' => '8.2.2.2',
  'dbname' => 'XXXXXX',
  'dbhost' => '127.0.0.1',
  'dbtableprefix' => 'oc_',
  'dbuser' => 'XXXXXX',
  'dbpassword' => 'XXXXXX',
  'loglevel' => 0,
  'logtimezone' => 'Europe/Berlin',
  'log_rotate_size' => 10485760,
  'installed' => true,
  'mail_smtpmode' => 'smtp',
  'mail_from_address' => 'XXXXXX',
  'mail_domain' => 'damken.com',
  'mail_smtpsecure' => 'XXXXXX',
  'mail_smtpauth' => 1,
  'mail_smtpauthtype' => 'XXXXXX',
  'mail_smtphost' => 'damken.com',
  'mail_smtpport' => 'XXXXXX',
  'mail_smtpname' => 'XXXXXX',
  'mail_smtppassword' => 'XXXXXX',
  'theme' => 'damken',
  'maintenance' => false,
  'appstoreenabled' => true,
  'appstoreurl' => 'https://api.owncloud.com/v1',
  'appstore.experimental.enabled' => true,
  'memcache.local' => '\\OC\\Memcache\\ACPu',
  'filelocking.enabled' => 'true',
  'memcache.distributed' => '\\OC\\Memcache\\Redis',
  'memcache.locking' => '\\OC\\Memcache\\Redis',
  'redis' =>
  array (
    'host' => '127.0.0.1',
    'port' => 6379,
    'timeout' => 0,
    'dbindex' => 0,
  ),

  'trashbin_retention_obligation' => '7,30',
  'versions_retention_obligation' => '15,90',
);

• Storage type and setup


NFS->
10.1.10.102:/mnt/md1/public/owncloud  /mnt/owncloud nfs soft,intr,rsize=8192,wsize=8192
@cdamken
Contributor
cdamken commented Feb 16, 2016

@MorrisJobke - We talked about this 😄

@PVince81 PVince81 added this to the 9.0-current milestone Feb 17, 2016
@PVince81 PVince81 added the sev2-high label Feb 17, 2016
@PVince81
Collaborator

@schiesbn @VicDeo this looks suspicious, especially the part with the badly truncated path

@VicDeo
Member
VicDeo commented Feb 17, 2016

@cdamken can you post

ls -ld /mnt/owncloud/data/carlos/files_versions/*/
and
SELECT * FROM oc_jobs;

@cdamken
Contributor
cdamken commented Feb 18, 2016

@VicDeo
Sure:

root@snoopy:/var/www/html/owncloud/config# ls -ld /mnt/owncloud/data/carlos/files_versions/*/
drwxr-xr-x 3 www-data www-data 65536 Okt  4 23:24 /mnt/owncloud/data/carlos/files_versions/ACHTUNG!_CAUTION!_ownCloud_server/
drwxr-xr-x 4 www-data www-data 65536 Okt 20 11:35 /mnt/owncloud/data/carlos/files_versions/Carlos ownCloud Support/
drwxr-xr-x 3 www-data www-data 65536 Sep 17 11:16 /mnt/owncloud/data/carlos/files_versions/Documentos/
drwxr-xr-x 2 www-data www-data 65536 Feb 16 12:03 /mnt/owncloud/data/carlos/files_versions/Install/
drwxr-xr-x 2 www-data www-data 65536 Jan 18 00:30 /mnt/owncloud/data/carlos/files_versions/InstantUpload/
drwxr-xr-x 4 www-data www-data 65536 Dez 20 17:10 /mnt/owncloud/data/carlos/files_versions/Libros y Audiolibros/
drwxr-xr-x 2 www-data www-data 65536 Feb 16 19:24 /mnt/owncloud/data/carlos/files_versions/Notes/
drwxr-xr-x 3 www-data www-data 65536 Sep 11 01:27 /mnt/owncloud/data/carlos/files_versions/ownCloud_Server/
drwxr-xr-x 3 www-data www-data 65536 Okt 16 23:11 /mnt/owncloud/data/carlos/files_versions/Private - cloud.damken.com/
MariaDB [ocdamken]>  SELECT * FROM oc_jobs;
+-----+-------------------------------------------------+-----------------------------------------------------------------------------+------------+
| id  | class                                           | argument                                                                    | last_run   |
+-----+-------------------------------------------------+-----------------------------------------------------------------------------+------------+
|   2 | OCA\Activity\BackgroundJob\ExpireActivities     | null                                                                        | 1455752701 |
|   3 | OCA\Files_sharing\Lib\DeleteOrphanedSharesJob   | null                                                                        | 1455790501 |
|  14 | OC\BackgroundJob\Legacy\RegularJob              | ["OCA\\Files_Antivirus\\Cron\\Task","run"]                                  | 1455791401 |
|  17 | OC\Log\Rotate                                   | "\/mnt\/owncloud\/data\/owncloud.log"                                       | 1455791401 |
| 538 | OCA\Activity\BackgroundJob\EmailNotification    | null                                                                        | 1455790502 |
| 539 | OC\Log\Rotate                                   | "\/media\/carlos\/69769a26-e202-424b-9acb-b65836c3a4d6\/data\/owncloud.log" | 1455791401 |
| 570 | OCA\Files_Trashbin\BackgroundJob\ExpireTrash    | null                                                                        | 1455791401 |
| 571 | OCA\Files_Versions\BackgroundJob\ExpireVersions | null                                                                        | 1455791403 |
+-----+-------------------------------------------------+-----------------------------------------------------------------------------+------------+
8 rows in set (0.00 sec)
@PVince81
Collaborator

@VicDeo any update ?

@VicDeo
Member
VicDeo commented Feb 23, 2016

@PVince81 I can assume the following:

  • rsions was a local directory name like this: `/ocDataDir/User/files/rsions so there is nothing suspicious here
  • the issue is likely related to trashbin expiration cron job
@cdamken
Contributor
cdamken commented Feb 23, 2016

rsions was a local directory name like this: `/ocDataDir/User/files/rsions so there is nothing suspicious here

Sorry but no, I never created a rsions folder in my /files user folder (carlos).

and the error is in files_versions

{"reqId":"TPU24DHyL7t1U1xX0xjE","remoteAddr":"","app":"PHP","message":"filesize(): stat failed for \/mnt\/owncloud\/data\/carlos\/files_versions\/rsions\/hello carlos.txt.v1444125868 at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#139","level":3,"time":"2016-02-23T12:30:09+01:00","method":"--","url":"--"}
root@snoopy:/mnt/owncloud/data# ls -la /mnt/owncloud/data/carlos/files_versions/* |grep carlos.txt
-rw-r--r-- 1 www-data www-data   117 Okt  6 12:16 /mnt/owncloud/data/carlos/files_versions/hello carlos.txt.v1444125868

The only file in files version is hello carlos.txt.v1444125868

all others are directories.

root@snoopy:/mnt/owncloud/data# ls -ld /mnt/owncloud/data/carlos/files_versions/
drwxr-xr-x 11 www-data www-data 65536 Feb 17 16:08 /mnt/owncloud/data/carlos/files_versions/
root@snoopy:/mnt/owncloud/data# ls -ld /mnt/owncloud/data/carlos/files_versions/*
drwxr-xr-x 3 www-data www-data 65536 Okt  4 23:24 /mnt/owncloud/data/carlos/files_versions/ACHTUNG!_CAUTION!_ownCloud_server
drwxr-xr-x 4 www-data www-data 65536 Okt 20 11:35 /mnt/owncloud/data/carlos/files_versions/Carlos ownCloud Support
drwxr-xr-x 3 www-data www-data 65536 Sep 17 11:16 /mnt/owncloud/data/carlos/files_versions/Documentos
-rw-r--r-- 1 www-data www-data   117 Okt  6 12:16 /mnt/owncloud/data/carlos/files_versions/hello carlos.txt.v1444125868
drwxr-xr-x 2 www-data www-data 65536 Feb 16 12:03 /mnt/owncloud/data/carlos/files_versions/Install
drwxr-xr-x 2 www-data www-data 65536 Jan 18 00:30 /mnt/owncloud/data/carlos/files_versions/InstantUpload
drwxr-xr-x 4 www-data www-data 65536 Dez 20 17:10 /mnt/owncloud/data/carlos/files_versions/Libros y Audiolibros
drwxr-xr-x 2 www-data www-data 65536 Feb 19 10:48 /mnt/owncloud/data/carlos/files_versions/Notes
drwxr-xr-x 3 www-data www-data 65536 Sep 11 01:27 /mnt/owncloud/data/carlos/files_versions/ownCloud_Server
drwxr-xr-x 3 www-data www-data 65536 Okt 16 23:11 /mnt/owncloud/data/carlos/files_versions/Private - cloud.damken.com
@PVince81
Collaborator

"rsions" looks like "files_versions" badly truncated, removing the 8 first characters.
Now what code path would remove the 8 first characters of a path ?

@VicDeo
Member
VicDeo commented Feb 23, 2016

@cdamken please post output for
SELECT * FROM oc_files_trash WHERE id LIKE '%hello carlos%';

@VicDeo VicDeo was assigned by PVince81 Feb 23, 2016
@cdamken
Contributor
cdamken commented Feb 24, 2016

@VicDeo here it is:

MariaDB [ocdamken]>  SELECT * FROM oc_files_trash WHERE id LIKE '%hello carlos%';
Empty set (0.00 sec)

MariaDB [ocdamken]>  SELECT * FROM oc_files_trash WHERE id LIKE '%carlos%';     Empty set (0.00 sec)

MariaDB [ocdamken]>  SELECT * FROM oc_files_trash WHERE id LIKE '%hello%';
Empty set (0.00 sec)

MariaDB [ocdamken]>
@cdamken
Contributor
cdamken commented Feb 24, 2016

@VicDeo @PVince81 @schiesbn checking forward in the database I saw that the file is the one that @schiesbn once shared with me over federated cloud:

MariaDB [ocdamken]>  SELECT * FROM oc_filecache WHERE name LIKE '%hello carlos%'                      ;
+--------+---------+----------------------------------------------------+-------                      ---------------------------+--------+------------------------------+----------+-                      ---------+------+------------+---------------+-----------+------------------+---                      -------------------------------+-------------+
| fileid | storage | path                                               | path_h                      ash                        | parent | name                         | mimetype |                       mimepart | size | mtime      | storage_mtime | encrypted | unencrypted_size | et                      ag                             | permissions |
+--------+---------+----------------------------------------------------+-------                      ---------------------------+--------+------------------------------+----------+-                      ---------+------+------------+---------------+-----------+------------------+---                      -------------------------------+-------------+
| 150177 |      46 |                                                    | d41d8c                      d98f00b204e9800998ecf8427e |     -1 | hello carlos.txt             |       13 |                             12 |  170 | 1444126471 |    1444125868 |         0 |                0 | a8                      c00d0a028899040ad216aafba14384 |          27 |
| 150181 |       1 | files_versions/hello carlos.txt.v1444125868        | 8a0b8c                      1840f0d95f287282455638b02d |    969 | hello carlos.txt.v1444125868 |       10 |                              5 |  117 | 1444126583 |    1444126583 |         0 |                0 | c6                      4a05821a3de3592c86b5f0b9b35553 |          27 |
| 627544 |       3 | carlos/files_versions/hello carlos.txt.v1444125868 | 4192f8                      74aa51e91eba18753b6dcdd66b |  14178 | hello carlos.txt.v1444125868 |       10 |                              5 |  117 | 1444126583 |    1444126583 |         0 |                0 | 92                      cb1702a1f445bc8a0d0be7d5bf9ef4 |          27 |
+--------+---------+----------------------------------------------------+-------                      ---------------------------+--------+------------------------------+----------+-                      ---------+------+------------+---------------+-----------+------------------+---                      -------------------------------+-------------+
3 rows in set (0.36 sec)

MariaDB [ocdamken]>  SELECT * FROM oc_activity WHERE subjectparams LIKE '%hello carlos%';
+-------------+------------+----------+--------------+--------+--------------+---------------+-----------------------+-----------------------------------------------------+---------+---------------+-------------------+-------------------------------------------------------+-------------+-----------+
| activity_id | timestamp  | priority | type         | user   | affecteduser | app           | subject               | subjectparams                                       | message | messageparams | file              | link                                                  | object_type | object_id |
+-------------+------------+----------+--------------+--------+--------------+---------------+-----------------------+-----------------------------------------------------+---------+---------------+-------------------+-------------------------------------------------------+-------------+-----------+
|        2575 | 1444126592 |       40 | file_changed | carlos | carlos       | files         | changed_self          | ["\/hello carlos.txt"]                              |         | []            | /hello carlos.txt | https://cloud.damken.com/index.php/apps/files?dir=%2F | NULL        |         0 |
|        2576 | 1444128149 |       30 | remote_share |        | carlos       | files_sharing | remote_share_unshared | ["schiesbn@xxxxxxxx.org","hello carlos.txt"]        |         | []            |                   |                                                       | NULL        |         0 |
+-------------+------------+----------+--------------+--------+--------------+---------------+-----------------------+-----------------------------------------------------+---------+---------------+-------------------+-------------------------------------------------------+-------------+-----------+
2 rows in set (0.28 sec)

MariaDB [ocdamken]>

Helps something?

@schiessle
Member

I agree with @PVince81 this really looks like we don't truncate the path correctly. I can remember that we fixed something regarding path truncating a few months ago. But don't remember for which versions

@VicDeo
Member
VicDeo commented Feb 24, 2016

@cdamken

checking forward in the database I saw that the file is the one that @schiesbn once shared with me over federated cloud:
Helps something?

yes, it makes it easier to reproduce as the file in question is not local.

@cdamken
Contributor
cdamken commented Feb 24, 2016

Great! :) that solves the second part of the conjob error.

how about the first part:

{"reqId":"cilXboWxEKT29Dzo6C88","remoteAddr":"","app":"PHP","message":"opendir(\/mnt\/owncloud\/data\USER\/files_trashbin\/files): failed to open dir: No such file or directory at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#96","level":3,"time":"2016-02-24T12:30:03+01:00","method":"--","url":"--"}

I get the error every 30 minutes and I notice that those users doesn't have
/mnt/owncloud/data/USER/files_trashbin , probably they haven't erase a file for now.

A workaround could be creating a folder for each users, but it's not the real solution, at least should marked as warning and not as error .

@schiessle
Member

@cdamken seems like you trashbin is completely empty, the path looks OK. Can you verify this?

The cron job to clean up the trashbin should probably first do a is_dir() check before it tries to open it, @VicDeo can you have a look at it? Thanks!

@VicDeo
Member
VicDeo commented Feb 24, 2016

@schiesbn pushed #22628

@cdamken
Contributor
cdamken commented Mar 1, 2016

@VicDeo

@schiesbn pushed #22628

that works good!, thanks.

yes, it makes it easier to reproduce as the file in question is not local.

About this federated error, its something I can do to help?

@cdamken
Contributor
cdamken commented Mar 15, 2016

@VicDeo, is there a fix for the federated error or should I just remove from the database?

@PVince81
Collaborator

@VicDeo @schiesbn ^

@VicDeo
Member
VicDeo commented Mar 28, 2016

@cdamken can you post result for select * from oc_storages where numeric_id in (1, 3);

this entry looks suspicious:

627544 | 3 | carlos/files_versions/hello carlos.txt.v1444125868

Namely, path should not start with uid:
carlos/files_versions/hello carlos.txt.v1444125868

@MorrisJobke
Member

Maybe it's a received federated cloud share?

@VicDeo
Member
VicDeo commented Mar 29, 2016

@MorrisJobke with filepathes carlos/files_versions/hello carlos.txt.v1444125868 and carlos/files_versions/hello carlos.txt.v1444125868?
I don't think so.

@cdamken
Contributor
cdamken commented Mar 29, 2016
MariaDB [ocdamken]> select * from oc_storages where numeric_id in (1, 3);
+----------------------------+------------+-----------+--------------+
| id                         | numeric_id | available | last_checked |
+----------------------------+------------+-----------+--------------+
| home::carlos               |          1 |         1 |         NULL |
| local::/mnt/owncloud/data/ |          3 |         1 |         NULL |
+----------------------------+------------+-----------+--------------+
2 rows in set (0.00 sec)

MariaDB [ocdamken]>

@MorrisJobke with filepathes carlos/files_versions/hello carlos.txt.v1444125868 and carlos/files_versions/hello carlos.txt.v1444125868?
I don't think so.

That was a federated share.

@VicDeo
Member
VicDeo commented Mar 29, 2016

@cdamken

That was a federated share.

yes, but these two version files are local.

@cdamken
Contributor
cdamken commented Mar 29, 2016

@VicDeo yes, and the file is local too:

root@snoopy:/mnt/owncloud/data/carlos/files_versions# ls -la | grep  carlos
-rw-r--r--  1 www-data www-data   117 Okt  6 12:16 hello carlos.txt.v1444125868
root@snoopy:/mnt/owncloud/data/carlos/files_versions#
@VicDeo
Member
VicDeo commented Mar 29, 2016

@cdamken I can't reproduce it locally with 8.2.2.
I don't see Files_Antivirus in the list of apps but it's cron task is present and being executed.
What version of files_antivirus do you have?
IIRC it had some kind of stripping prefixes on home storages in past.

@cdamken
Contributor
cdamken commented Mar 30, 2016

@cdamken I can't reproduce it locally with 8.2.2.
I don't see Files_Antivirus in the list of apps but it's cron task is present and being executed.
What version of files_antivirus do you have?

No files antivirus installed

|  14 | OC\BackgroundJob\Legacy\RegularJob              | ["OCA\\Files_Antivirus\\Cron\\Task","run"]                                  | 1455791401 |

You are right, th oc_jobs shows antivirus, but there are other wrong stuf tu be handle like:

| 539 | OC\Log\Rotate                                   | "\/media\/carlos\/69769a26-e202-424b-9acb-b65836c3a4d6\/data\/owncloud.log" | 1459341901 |

That folder does not exist (But I think that is another issue)

I saw today this:

{"reqId":"\/yOGVbEOcLfvJa6395B9","remoteAddr":"","app":"PHP","message":"filesize(): stat failed for \/mnt\/owncloud\/data\/carlos\/files_versions\/rsions\/hello carlos.txt.v1444125868 at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#139","level":3,"time":"2016-03-30T14:45:01+02:00","method":"--","url":"--"}
{"reqId":"\/yOGVbEOcLfvJa6395B9","remoteAddr":"","app":"PHP","message":"filesize(): stat failed for \/mnt\/owncloud\/data\/felix\/files_versions\/sions\/New Document.odt.v1457450628 at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#139","level":3,"time":"2016-03-30T14:45:02+02:00","method":"--","url":"--"}
{"reqId":"\/yOGVbEOcLfvJa6395B9","remoteAddr":"","app":"PHP","message":"filesize(): stat failed for \/mnt\/owncloud\/data\/martinw\/files_versions\/ersions\/reverb.html.v1458159540 at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#139","level":3,"time":"2016-03-30T14:45:02+02:00","method":"--","url":"--"}

You can see: rsions, sions and ersions after /files_versions/

@cdamken
Contributor
cdamken commented Mar 31, 2016

@VicDeo I suppose you mean: ./apps/files_versions/lib/storage.php?

@VicDeo
Member
VicDeo commented Mar 31, 2016

@cdamken exactly

@cdamken
Contributor
cdamken commented Mar 31, 2016

only copying the lines: 508-518

{"reqId":"Q3Ws2qLA8v6466BOj6Ii","remoteAddr":"","app":"files_versions","message":"files_versions\/rsions\/hello carlos.txt.v1444125868 not exist. Original path is carlos\/files_versions\/hello carlos.txt.v1444125868","level":2,"time":"2016-03-31T18:10:04+02:00","method":"--","url":"--"}
{"reqId":"Q3Ws2qLA8v6466BOj6Ii","remoteAddr":"","app":"PHP","message":"filesize(): stat failed for \/mnt\/owncloud\/data\/carlos\/files_versions\/rsions\/hello carlos.txt.v1444125868 at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#139","level":3,"time":"2016-03-31T18:10:04+02:00","method":"--","url":"--"}
{"reqId":"Q3Ws2qLA8v6466BOj6Ii","remoteAddr":"","app":"files_versions","message":"files_versions\/sions\/New Document.odt.v1457450628 not exist. Original path is felix\/files_versions\/New Document.odt.v1457450628","level":2,"time":"2016-03-31T18:10:04+02:00","method":"--","url":"--"}
{"reqId":"Q3Ws2qLA8v6466BOj6Ii","remoteAddr":"","app":"PHP","message":"filesize(): stat failed for \/mnt\/owncloud\/data\/felix\/files_versions\/sions\/New Document.odt.v1457450628 at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#139","level":3,"time":"2016-03-31T18:10:04+02:00","method":"--","url":"--"}
{"reqId":"Q3Ws2qLA8v6466BOj6Ii","remoteAddr":"","app":"files_versions","message":"files_versions\/ersions\/reverb.html.v1458159540 not exist. Original path is martinw\/files_versions\/reverb.html.v1458159540","level":2,"time":"2016-03-31T18:10:04+02:00","method":"--","url":"--"}
{"reqId":"Q3Ws2qLA8v6466BOj6Ii","remoteAddr":"","app":"PHP","message":"filesize(): stat failed for \/mnt\/owncloud\/data\/martinw\/files_versions\/ersions\/reverb.html.v1458159540 at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#139","level":3,"time":"2016-03-31T18:10:04+02:00","method":"--","url":"--"}
{"reqId":"Q3Ws2qLA8v6466BOj6Ii","remoteAddr":"","app":"files_versions","message":"files_versions\/versions\/Presentation1 [Repaired].pptx.v1459354894 not exist. Original path is password\/files_versions\/Presentation1 [Repaired].pptx.v1459354894","level":2,"time":"2016-03-31T18:10:04+02:00","method":"--","url":"--"}
{"reqId":"Q3Ws2qLA8v6466BOj6Ii","remoteAddr":"","app":"PHP","message":"filesize(): stat failed for \/mnt\/owncloud\/data\/password\/files_versions\/versions\/Presentation1 [Repaired].pptx.v1459354894 at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#139","level":3,"time":"2016-03-31T18:10:04+02:00","method":"--","url":"--"}

replacing the whole file.. i have no logs when I run sudo -u www-data php -f cron.php

@cdamken
Contributor
cdamken commented Mar 31, 2016

If I run the cron.php:

{"reqId":"BQJ49V60cIhoD2OIPhB5","remoteAddr":"","app":"DeleteOrphanedSharesJob","message":"0 orphaned share(s) deleted","level":0,"time":"2016-03-31T18:35:55+02:00","method":"--","url":"--"}
@VicDeo
Member
VicDeo commented Mar 31, 2016

hm.. might be an opcode cache issue.

@cdamken
Contributor
cdamken commented Apr 1, 2016

Yes, that is normal from time to time appears, about the file versions I think its fixed, since yesterday does not appear the erros anymore.

@VicDeo Thanks a lot!

@VicDeo
Member
VicDeo commented Apr 1, 2016

@cdamken actually I've done no changes in business logic
These 10 lines just add logging for files that are returned by View::getDirectoryContents but do not exist in the current directory.

@cdamken
Contributor
cdamken commented Apr 1, 2016

You are right, now just came again the message:

{"reqId":"0GoDdWMpaOJP38H9ifuX","remoteAddr":"","app":"files_versions","message":"files_versions\/rsions\/hello carlos.txt.v1444125868 not exist. Original path is carlos\/files_versions\/hello carlos.txt.v1444125868","level":2,"time":"2016-04-01T14:45:08+02:00","method":"--","url":"--"}
{"reqId":"0GoDdWMpaOJP38H9ifuX","remoteAddr":"","app":"PHP","message":"filesize(): stat failed for \/mnt\/owncloud\/data\/carlos\/files_versions\/rsions\/hello carlos.txt.v1444125868 at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#139","level":3,"time":"2016-04-01T14:45:08+02:00","method":"--","url":"--"}
{"reqId":"0GoDdWMpaOJP38H9ifuX","remoteAddr":"","app":"files_versions","message":"files_versions\/sions\/New Document.odt.v1457450628 not exist. Original path is felix\/files_versions\/New Document.odt.v1457450628","level":2,"time":"2016-04-01T14:45:08+02:00","method":"--","url":"--"}
{"reqId":"0GoDdWMpaOJP38H9ifuX","remoteAddr":"","app":"PHP","message":"filesize(): stat failed for \/mnt\/owncloud\/data\/felix\/files_versions\/sions\/New Document.odt.v1457450628 at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#139","level":3,"time":"2016-04-01T14:45:08+02:00","method":"--","url":"--"}
{"reqId":"0GoDdWMpaOJP38H9ifuX","remoteAddr":"","app":"files_versions","message":"files_versions\/ersions\/reverb.html.v1458159540 not exist. Original path is martinw\/files_versions\/reverb.html.v1458159540","level":2,"time":"2016-04-01T14:45:08+02:00","method":"--","url":"--"}
{"reqId":"0GoDdWMpaOJP38H9ifuX","remoteAddr":"","app":"PHP","message":"filesize(): stat failed for \/mnt\/owncloud\/data\/martinw\/files_versions\/ersions\/reverb.html.v1458159540 at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#139","level":3,"time":"2016-04-01T14:45:08+02:00","method":"--","url":"--"}
{"reqId":"0GoDdWMpaOJP38H9ifuX","remoteAddr":"","app":"files_versions","message":"files_versions\/versions\/Presentation1 [Repaired].pptx.v1459354894 not exist. Original path is password\/files_versions\/Presentation1 [Repaired].pptx.v1459354894","level":2,"time":"2016-04-01T14:45:08+02:00","method":"--","url":"--"}
{"reqId":"0GoDdWMpaOJP38H9ifuX","remoteAddr":"","app":"PHP","message":"filesize(): stat failed for \/mnt\/owncloud\/data\/password\/files_versions\/versions\/Presentation1 [Repaired].pptx.v1459354894 at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#139","level":3,"time":"2016-04-01T14:45:08+02:00","method":"--","url":"--"}
@cdamken
Contributor
cdamken commented Apr 11, 2016

@cdamken please check with this lib/storage.php https://github.com/owncloud/core/blob/3007b481fe4469a3a0c7d01a70ef31cdf5ce071e/apps/files_versions/lib/storage.php

@VicDeo Here are the logs with the new storage.php:

{"reqId":"SoiwXKBILZWj3O4VNGTb","remoteAddr":"","app":"PHP","message":"filesize(): stat failed for \/mnt\/owncloud\/data\/carlos\/files_versions\/rsions\/hello carlos.txt.v1444125868 at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#139","level":3,"time":"2016-04-11T11:18:35+02:00","method":"--","url":"--"}
{"reqId":"SoiwXKBILZWj3O4VNGTb","remoteAddr":"","app":"PHP","message":"filesize(): stat failed for \/mnt\/owncloud\/data\/felix\/files_versions\/sions\/New Document.odt.v1457450628 at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#139","level":3,"time":"2016-04-11T11:18:35+02:00","method":"--","url":"--"}
{"reqId":"SoiwXKBILZWj3O4VNGTb","remoteAddr":"","app":"PHP","message":"filesize(): stat failed for \/mnt\/owncloud\/data\/martinw\/files_versions\/ersions\/reverb.html.v1458159540 at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#139","level":3,"time":"2016-04-11T11:18:35+02:00","method":"--","url":"--"}
{"reqId":"SoiwXKBILZWj3O4VNGTb","remoteAddr":"","app":"PHP","message":"filesize(): stat failed for \/mnt\/owncloud\/data\/password\/files_versions\/versions\/Presentation1 [Repaired].pptx.v1459354894 at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#139","level":3,"time":"2016-04-11T11:18:35+02:00","method":"--","url":"--"}
@VicDeo
Member
VicDeo commented Apr 12, 2016

@cdamken err... I see no difference.
I wish there were a complete call stack.

Is it still 8.2.2 bt the way?

@cmonteroluque
Contributor

@VicDeo 8.2.4, needs resolution

@cdamken
Contributor
cdamken commented Apr 19, 2016

Is it still 8.2.2 bt the way?
@VicDeo Yes, still 8.2.2. Its something I can do?

@PVince81
Collaborator

@cdamken can you enable the PHP module XDebug on your server ? When enabled, the logs should then contain more information like the stack traces that @VicDeo needs

@cdamken
Contributor
cdamken commented Apr 21, 2016

@PVince81 @VicDeo I enabled XDebug, but I only got the same logs:

{"reqId":"FpCB3ujmSpZRp\/aIyJ9v","remoteAddr":"","app":"DeleteOrphanedSharesJob","message":"0 orphaned share(s) deleted","level":0,"time":"2016-04-21T12:45:02+02:00","method":"--","url":"--"}
{"reqId":"FpCB3ujmSpZRp\/aIyJ9v","remoteAddr":"","app":"PHP","message":"filesize(): stat failed for \/mnt\/owncloud\/data\/carlos\/files_versions\/rsions\/hello carlos.txt.v1444125868 at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#139","level":3,"time":"2016-04-21T12:45:02+02:00","method":"--","url":"--"}
{"reqId":"FpCB3ujmSpZRp\/aIyJ9v","remoteAddr":"","app":"PHP","message":"filesize(): stat failed for \/mnt\/owncloud\/data\/felix\/files_versions\/sions\/New Document.odt.v1457450628 at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#139","level":3,"time":"2016-04-21T12:45:02+02:00","method":"--","url":"--"}
{"reqId":"FpCB3ujmSpZRp\/aIyJ9v","remoteAddr":"","app":"PHP","message":"filesize(): stat failed for \/mnt\/owncloud\/data\/martinw\/files_versions\/ersions\/reverb.html.v1458159540 at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#139","level":3,"time":"2016-04-21T12:45:02+02:00","method":"--","url":"--"}
{"reqId":"FpCB3ujmSpZRp\/aIyJ9v","remoteAddr":"","app":"PHP","message":"filesize(): stat failed for \/mnt\/owncloud\/data\/password\/files_versions\/versions\/Presentation1 [Repaired].pptx.v1459354894 at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#139","level":3,"time":"2016-04-21T12:45:02+02:00","method":"--","url":"--"}
{"reqId":"qrYaoyP1gkxQyExCMBOU","remoteAddr":"","app":"files_trashbin","message":"Remove \"Notes\" from trashbin because it exceeds max retention obligation term.","level":1,"time":"2016-04-21T13:00:02+02:00","method":"--","url":"--"}
{"reqId":"Cy9dFdgHzJ0jvAB3Xbrx","remoteAddr":"","app":"DeleteOrphanedSharesJob","message":"0 orphaned share(s) deleted","level":0,"time":"2016-04-21T13:15:01+02:00","method":"--","url":"--"}
{"reqId":"sZNdKmEpE206qqxCTCum","remoteAddr":"93.202.88.105","app":"files_external","message":"Forbidden. Your app is making too many requests and is being rate limited. 503s can trigger on a per-app or per-user basis.","level":3,"time":"2016-04-21T12:26:51+02:00","method":"PROPFIND","url":"\/remote.php\/webdav\/"}
{"reqId":"FpCB3ujmSpZRp\/aIyJ9v","remoteAddr":"","app":"DeleteOrphanedSharesJob","message":"0 orphaned share(s) deleted","level":0,"time":"2016-04-21T12:45:02+02:00","method":"--","url":"--"}
{"reqId":"FpCB3ujmSpZRp\/aIyJ9v","remoteAddr":"","app":"PHP","message":"filesize(): stat failed for \/mnt\/owncloud\/data\/carlos\/files_versions\/rsions\/hello carlos.txt.v1444125868 at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#139","level":3,"time":"2016-04-21T12:45:02+02:00","method":"--","url":"--"}
{"reqId":"FpCB3ujmSpZRp\/aIyJ9v","remoteAddr":"","app":"PHP","message":"filesize(): stat failed for \/mnt\/owncloud\/data\/felix\/files_versions\/sions\/New Document.odt.v1457450628 at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#139","level":3,"time":"2016-04-21T12:45:02+02:00","method":"--","url":"--"}
{"reqId":"FpCB3ujmSpZRp\/aIyJ9v","remoteAddr":"","app":"PHP","message":"filesize(): stat failed for \/mnt\/owncloud\/data\/martinw\/files_versions\/ersions\/reverb.html.v1458159540 at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#139","level":3,"time":"2016-04-21T12:45:02+02:00","method":"--","url":"--"}
{"reqId":"FpCB3ujmSpZRp\/aIyJ9v","remoteAddr":"","app":"PHP","message":"filesize(): stat failed for \/mnt\/owncloud\/data\/password\/files_versions\/versions\/Presentation1 [Repaired].pptx.v1459354894 at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#139","level":3,"time":"2016-04-21T12:45:02+02:00","method":"--","url":"--"}
{"reqId":"qrYaoyP1gkxQyExCMBOU","remoteAddr":"","app":"files_trashbin","message":"Remove \"Notes\" from trashbin because it exceeds max retention obligation term.","level":1,"time":"2016-04-21T13:00:02+02:00","method":"--","url":"--"}
{"reqId":"Cy9dFdgHzJ0jvAB3Xbrx","remoteAddr":"","app":"DeleteOrphanedSharesJob","message":"0 orphaned share(s) deleted","level":0,"time":"2016-04-21T13:15:01+02:00","method":"--","url":"--"}
{"reqId":"YLUOzxfauG3RFlGPKA+3","remoteAddr":"","app":"DeleteOrphanedSharesJob","message":"0 orphaned share(s) deleted","level":0,"time":"2016-04-21T13:30:02+02:00","method":"--","url":"--"}
{"reqId":"YLUOzxfauG3RFlGPKA+3","remoteAddr":"","app":"PHP","message":"filesize(): stat failed for \/mnt\/owncloud\/data\/carlos\/files_versions\/rsions\/hello carlos.txt.v1444125868 at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#139","level":3,"time":"2016-04-21T13:30:03+02:00","method":"--","url":"--"}
{"reqId":"YLUOzxfauG3RFlGPKA+3","remoteAddr":"","app":"PHP","message":"filesize(): stat failed for \/mnt\/owncloud\/data\/felix\/files_versions\/sions\/New Document.odt.v1457450628 at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#139","level":3,"time":"2016-04-21T13:30:03+02:00","method":"--","url":"--"}
{"reqId":"YLUOzxfauG3RFlGPKA+3","remoteAddr":"","app":"PHP","message":"filesize(): stat failed for \/mnt\/owncloud\/data\/martinw\/files_versions\/ersions\/reverb.html.v1458159540 at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#139","level":3,"time":"2016-04-21T13:30:03+02:00","method":"--","url":"--"}
{"reqId":"YLUOzxfauG3RFlGPKA+3","remoteAddr":"","app":"PHP","message":"filesize(): stat failed for \/mnt\/owncloud\/data\/password\/files_versions\/versions\/Presentation1 [Repaired].pptx.v1459354894 at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#139","level":3,"time":"2016-04-21T13:30:03+02:00","method":"--","url":"--"}

@PVince81
Collaborator

@VicDeo any other ideas ?

There seems to be a substr error somewhere: mnt\/owncloud\/data\/carlos\/files_versions\/rsions\/.
Maybe check the versions code for all string operations / substrings to find where this could happen ?

@VicDeo
Member
VicDeo commented Apr 25, 2016 edited

@PVince81 may be patching /lib/private/files/storage/local.php to log debug_backtrace for non-existing files would be better?

@PVince81
Collaborator

@VicDeo whichever can advance this investigation, yes. Please provide a patch for @cdamken then.

@VicDeo
Member
VicDeo commented Apr 25, 2016

@cdamken please change lib/private/files/storage/local.php according to this file https://gist.github.com/VicDeo/4b2dd302b02976ce7660a3c299feb096

you need to replace filesize function only
https://gist.github.com/VicDeo/4b2dd302b02976ce7660a3c299feb096#file-local-php-L130-L153

@VicDeo
Member
VicDeo commented Apr 25, 2016 edited

@cdamken After that filesize(): stat failed will disappear and you will have entries from app called debug_22450 instead:

Warning debug_22450 #0 OC\Files\Storage\Local->filesize(thumbnails/36/48-48.png) called at [/home/deo/public_html/820/lib/private/files/storage/wrapper/wrapper.php:141] #1 OC\Files\Storage\Wrapper\Wrapper->filesize(thumbnails/36/48-48.png) called at [/home/deo/public_html/820/lib/private/files/storage/wrapper/encryption.php:139] #2 OC\Files\Storage\Wrapper\Encryption->filesize(thumbnails/36/48-48.png) called at [/home/deo/public_html/820/lib/private/files/storage/wrapper/encryption.php:353] #3 OC\Files\Storage\Wrapper\Encryption->fopen(thumbnails/36/48-48.png, r) called at [/home/deo/public_html/820/lib/private/files/storage/wrapper/wrapper.php:286] #4 OC\Files\Storage\Wrapper\Wrapper->fopen(thumbnails/36/48-48.png, r) called at [/home/deo/public_html/820/lib/private/files/view.php:1021] #5 OC\Files\View->basicOperation(fopen, thumbnails/36/48-48.png, Array ([0] => read), r) called at [/home/deo/public_html/820/lib/private/files/view.php:871] #6 OC\Files\View->fopen(thumbnails/36/48-48.png, r) called at [/home/deo/public_html/820/lib/private/preview.php:814] #7 OC\Preview->getCachedPreview(36, thumbnails/36/48-48.png) called at [/home/deo/public_html/820/lib/private/preview.php:766] #8 OC\Preview->getPreview() called at [/home/deo/public_html/820/lib/private/preview.php:795] #9 OC\Preview->showPreview() called at [/home/deo/public_html/820/core/ajax/preview.php:63] #10 require_once(/home/deo/public_html/820/core/ajax/preview.php) called at [/home/deo/public_html/820/lib/private/route/route.php(154) : runtime-created function:1] #11 __lambda_func(Array ([_route] => core_ajax_preview)) #12 call_user_func(lambda_219, Array ([_route] => core_ajax_preview)) called at [/home/deo/public_html/820/lib/private/route/router.php:291] #13 OC\Route\Router->match(/core/preview.png) called at [/home/deo/public_html/820/lib/base.php:851] #14 OC::handleRequest() called at [/home/deo/public_html/820/index.php:39] 2016-04-25T17:13:26+00:00
Warning debug_22450 Non-existing path. Path: thumbnails/36/48-48.png. Fullpath: /home/deo/public_html/820/data/Deo/thumbnails/36/48-48.png. 2016-04-25T17:13:26+00:00

Please post them here.

@cdamken
Contributor
cdamken commented Apr 26, 2016
{"reqId":"MUdN8xmQIrEkoO1vO2ay","remoteAddr":"","app":"PHP","message":"filesize(): stat failed for \/mnt\/owncloud\/data\/carlos\/files_versions\/rsions\/hello carlos.txt.v1444125868 at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#139","level":3,"time":"2016-04-26T12:15:02+02:00","method":"--","url":"--"}
{"reqId":"MUdN8xmQIrEkoO1vO2ay","remoteAddr":"","app":"PHP","message":"filesize(): stat failed for \/mnt\/owncloud\/data\/felix\/files_versions\/sions\/New Document.odt.v1457450628 at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#139","level":3,"time":"2016-04-26T12:15:03+02:00","method":"--","url":"--"}
{"reqId":"MUdN8xmQIrEkoO1vO2ay","remoteAddr":"","app":"PHP","message":"filesize(): stat failed for \/mnt\/owncloud\/data\/martinw\/files_versions\/ersions\/reverb.html.v1458159540 at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#139","level":3,"time":"2016-04-26T12:15:03+02:00","method":"--","url":"--"}
{"reqId":"MUdN8xmQIrEkoO1vO2ay","remoteAddr":"","app":"PHP","message":"filesize(): stat failed for \/mnt\/owncloud\/data\/password\/files_versions\/versions\/Presentation1 [Repaired].pptx.v1459354894 at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#139","level":3,"time":"2016-04-26T12:15:03+02:00","method":"--","url":"--"}
{"reqId":"MUdN8xmQIrEkoO1vO2ay","remoteAddr":"","app":"PHP","message":"filesize(): stat failed for \/mnt\/owncloud\/data\/pisoko\/files_versions\/rsions\/New Users - PLEASE READ THIS FIRST!.txt.v1461575858 at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#139","level":3,"time":"2016-04-26T12:15:03+02:00","method":"--","url":"--"}
{"reqId":"uCyH7Ru1BKIw1Ty1ui78","remoteAddr":"","app":"PHP","message":"filesize(): stat failed for \/mnt\/owncloud\/data\/carlos\/files_versions\/rsions\/hello carlos.txt.v1444125868 at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#139","level":3,"time":"2016-04-26T13:00:02+02:00","method":"--","url":"--"}
{"reqId":"uCyH7Ru1BKIw1Ty1ui78","remoteAddr":"","app":"PHP","message":"filesize(): stat failed for \/mnt\/owncloud\/data\/felix\/files_versions\/sions\/New Document.odt.v1457450628 at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#139","level":3,"time":"2016-04-26T13:00:02+02:00","method":"--","url":"--"}
{"reqId":"uCyH7Ru1BKIw1Ty1ui78","remoteAddr":"","app":"PHP","message":"filesize(): stat failed for \/mnt\/owncloud\/data\/martinw\/files_versions\/ersions\/reverb.html.v1458159540 at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#139","level":3,"time":"2016-04-26T13:00:02+02:00","method":"--","url":"--"}
{"reqId":"uCyH7Ru1BKIw1Ty1ui78","remoteAddr":"","app":"PHP","message":"filesize(): stat failed for \/mnt\/owncloud\/data\/password\/files_versions\/versions\/Presentation1 [Repaired].pptx.v1459354894 at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#139","level":3,"time":"2016-04-26T13:00:02+02:00","method":"--","url":"--"}
{"reqId":"uCyH7Ru1BKIw1Ty1ui78","remoteAddr":"","app":"PHP","message":"filesize(): stat failed for \/mnt\/owncloud\/data\/pisoko\/files_versions\/rsions\/New Users - PLEASE READ THIS FIRST!.txt.v1461575858 at \/var\/www\/html\/owncloud\/lib\/private\/files\/storage\/local.php#139","level":3,"time":"2016-04-26T13:00:02+02:00","method":"--","url":"--"}
@VicDeo
Member
VicDeo commented Apr 26, 2016 edited

@cdamken nope, looks like previous version of lib/private/files/storage/local.php is still cached somewhere because it still reports about filesize() and not file_exists()

@cdamken
Contributor
cdamken commented Apr 26, 2016

I modify the file as you told me 😄 and restarted the Apache

 if (!file_exists($fullPath)){
@VicDeo
Member
VicDeo commented Apr 26, 2016

ok, it comes from the place that I initially spotted https://github.com/owncloud/core/blob/stable8.2/apps/files_versions/lib/storage.php#L518

When files are aggregated by this piece of code

        $view = new \OC\Files\View('/' . $uid . '/');
        $dirs = array(self::VERSIONS_ROOT);
        $versions = array();
        while (!empty($dirs)) {
            $dir = array_pop($dirs);
            $files = $view->getDirectoryContent($dir);
            foreach ($files as $file) {
                if ($file['type'] === 'dir') {
                    array_push($dirs, $file['path']);
                } else {
                    $versionsBegin = strrpos($file['path'], '.v');
                    $relPathStart = strlen(self::VERSIONS_ROOT);
                    $version = substr($file['path'], $versionsBegin + 2);
                    $relpath = substr($file['path'], $relPathStart, $versionsBegin - $relPathStart);
                    $key = $version . '#' . $relpath;
                    $versions[$key] = array('path' => $relpath, 'timestamp' => $version);
                }
            }
        }

$view->getDirectoryContent($dir) sometimes returns a path relative to datadir instead of datadir/$uid which is specified as a view root dir

@VicDeo
Member
VicDeo commented Apr 27, 2016 edited

@icewind1991 could you please have a quick look what might wrong with the code #22450 (comment)

Short story:

  • OC 8.2.2
  • cron task
$view = new \OC\Files\View('/carlos/');
$files = $view->getDirectoryContent($dir);
foreach ($files as $file) {
             //  "files_versions/filename" is expected
            $file['path']; // "carlos/files_versions/filename" actual
}
@VicDeo
Member
VicDeo commented Apr 28, 2016

@cdamken please execute this file and post the output
https://gist.github.com/VicDeo/6a715322dfe1498ee73ea8455d923958

@cdamken
Contributor
cdamken commented May 3, 2016

@VicDeo , here it is:

root@snoopy:/var/www/html/owncloud# sudo -u www-data php test.php
array(14) {
  'fileid' =>
  string(6) "627544"
  'storage' =>
  string(1) "3"
  'path' =>
  string(50) "carlos/files_versions/hello carlos.txt.v1444125868"
  'parent' =>
  string(5) "14178"
  'name' =>
  string(28) "hello carlos.txt.v1444125868"
  'mimetype' =>
  string(24) "application/octet-stream"
  'mimepart' =>
  string(11) "application"
  'size' =>
  int(117)
  'mtime' =>
  int(1444126583)
  'storage_mtime' =>
  int(1444126583)
  'encrypted' =>
  string(1) "0"
  'etag' =>
  string(32) "92cb1702a1f445bc8a0d0be7d5bf9ef4"
  'permissions' =>
  int(27)
  'type' =>
  string(4) "file"
}
root@snoopy:/var/www/html/owncloud#
@VicDeo
Member
VicDeo commented May 3, 2016

@cdamken please post a result for the following query:
SELECT * FROM oc_storages WHERE numeric_id=3;

@VicDeo
Member
VicDeo commented May 3, 2016

Might be related to #24000

@cdamken
Contributor
cdamken commented May 3, 2016

@VicDeo

MariaDB [ocdamken]> SELECT * FROM oc_storages WHERE numeric_id=3;
+----------------------------+------------+-----------+--------------+
| id                         | numeric_id | available | last_checked |
+----------------------------+------------+-----------+--------------+
| local::/mnt/owncloud/data/ |          3 |         1 |         NULL |
+----------------------------+------------+-----------+--------------+
1 row in set (0.00 sec)

MariaDB [ocdamken]>
@VicDeo
Member
VicDeo commented May 4, 2016

it's local 😠

@cdamken cdamken added the blue-ticket label May 10, 2016
@cdamken
Contributor
cdamken commented May 10, 2016

yes, In this case the original file hello carlos.txt was shared via Federated Cloud.

Now is a blue ticket too 😢

The customer has a cronjob and gets after the each filescan --all:

filesize(): stat failed for /opt/owncloud_data/B9770D11-0569-43FF-8A0A-7FCB11257219/files_versions/3FF-8A0A-7FCB11257219/files_versions/test.sh.v1458304233 at /var/www/owncloud/lib/private/files/storage/local.php#139 

I will ask from more information (for now he hasn't reply to my emails)

00005434

@VicDeo
Member
VicDeo commented May 12, 2016

@cdamken please apply this commit and don't forget that your server has opcode cache enabled ;)
4b6f04a

@VicDeo
Member
VicDeo commented May 13, 2016

@cdamken was the last patch helpful to get rid of this immortal version?

@VicDeo
Member
VicDeo commented May 17, 2016

@PVince81
Fix for truncated path \/files_versions\/rsions\/hello carlos.txt.v1444125868 is pushed as #24673

@PVince81
Collaborator

Thanks for the investigation, guys!

@PVince81
Collaborator

This is really weird. From looking at the fix it looks like one cannot trust the output of getDirectoryContents

@cdamken
Contributor
cdamken commented May 17, 2016

Thanks a lot @VicDeo

@VicDeo
Member
VicDeo commented May 17, 2016 edited

@PVince81 From #22450 (comment) is evident that path is being truncated by length of uid.

I got no response from @icewind1991 on #22450 (comment) so decided to fix it locally.

My local 8.2.2 instance produces correct path even for versions with federated shares so I don't know how to reproduce it.

@PVince81 PVince81 added a commit that referenced this issue Jun 2, 2016
@VicDeo @PVince81 VicDeo + PVince81 Construct path to the version file from the current directory and fil…
…ename. Fixes #22450
d82df7e
@PVince81 PVince81 closed this in #24673 Jun 3, 2016
@cdamken
Contributor
cdamken commented Jun 8, 2016

Nice!, thanks a lot!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment