BadMethodCallException in scanner from cron #25506

PVince81 · 2016-07-18T07:58:27Z

Steps

Running cron on my system, reproducible always.

Logs

{"reqId":"bWfFLm+WCGs9gCLS9hJs","remoteAddr":"","app":"cron","message":"Finished job with ID 5","level":0,"time":"2016-07-18T07:00:01+00:00","method":"--","url":"--","user":"--"}
{"reqId":"bWfFLm+WCGs9gCLS9hJs","remoteAddr":"","app":"cron","message":"Run job with ID 25","level":0,"time":"2016-07-18T07:00:01+00:00","method":"--","url":"--","user":"--"}
{"reqId":"bWfFLm+WCGs9gCLS9hJs","remoteAddr":"","app":"cron","message":"Finished job with ID 25","level":0,"time":"2016-07-18T07:00:01+00:00","method":"--","url":"--","user":"--"}
{"reqId":"bWfFLm+WCGs9gCLS9hJs","remoteAddr":"","app":"cron","message":"Run job with ID 26","level":0,"time":"2016-07-18T07:00:01+00:00","method":"--","url":"--","user":"--"}
{"reqId":"bWfFLm+WCGs9gCLS9hJs","remoteAddr":"","app":"cron","message":"Finished job with ID 26","level":0,"time":"2016-07-18T07:00:01+00:00","method":"--","url":"--","user":"--"}
{"reqId":"bWfFLm+WCGs9gCLS9hJs","remoteAddr":"","app":"cron","message":"Run job with ID 303","level":0,"time":"2016-07-18T07:00:01+00:00","method":"--","url":"--","user":"--"}
{"reqId":"bWfFLm+WCGs9gCLS9hJs","remoteAddr":"","app":"no app in context","message":"Invalidating tokens older than 2016-07-17T07:00:01+00:00","level":1,"time":"2016-07-18T07:00:01+00:00","method":"--","url":"--","user":"--"}
{"reqId":"bWfFLm+WCGs9gCLS9hJs","remoteAddr":"","app":"cron","message":"Finished job with ID 303","level":0,"time":"2016-07-18T07:00:01+00:00","method":"--","url":"--","user":"--"}
{"reqId":"bWfFLm+WCGs9gCLS9hJs","remoteAddr":"","app":"cron","message":"Run job with ID 305","level":0,"time":"2016-07-18T07:00:01+00:00","method":"--","url":"--","user":"--"}
{"reqId":"bWfFLm+WCGs9gCLS9hJs","remoteAddr":"","app":"DeleteOrphanedSharesJob","message":"0 orphaned share(s) deleted","level":0,"time":"2016-07-18T07:00:01+00:00","method":"--","url":"--","user":"--"}
{"reqId":"bWfFLm+WCGs9gCLS9hJs","remoteAddr":"","app":"cron","message":"Finished job with ID 305","level":0,"time":"2016-07-18T07:00:01+00:00","method":"--","url":"--","user":"--"}
{"reqId":"bWfFLm+WCGs9gCLS9hJs","remoteAddr":"","app":"cron","message":"Run job with ID 306","level":0,"time":"2016-07-18T07:00:01+00:00","method":"--","url":"--","user":"--"}
{"reqId":"bWfFLm+WCGs9gCLS9hJs","remoteAddr":"","app":"cron","message":"Finished job with ID 306","level":0,"time":"2016-07-18T07:00:01+00:00","method":"--","url":"--","user":"--"}
{"reqId":"bWfFLm+WCGs9gCLS9hJs","remoteAddr":"","app":"cron","message":"Run job with ID 165","level":0,"time":"2016-07-18T07:00:01+00:00","method":"--","url":"--","user":"--"}
{"reqId":"bWfFLm+WCGs9gCLS9hJs","remoteAddr":"","app":"files","message":"Exception: {\"Exception\":\"BadMethodCallException\",\"Message\":\"Not in batch\",\"Code\":0,\"Trace\":\"
#0 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/private\\\/Files\\\/Utils\\\/Scanner.php(143): OC\\\\Files\\\\Cache\\\\Propagator->commitBatch()\\n
#1 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/apps\\\/files\\\/lib\\\/BackgroundJob\\\/ScanFiles.php(87): OC\\\\Files\\\\Utils\\\\Scanner->backgroundScan('')\\n
#2 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/apps\\\/files\\\/lib\\\/BackgroundJob\\\/ScanFiles.php(111): OCA\\\\Files\\\\BackgroundJob\\\\ScanFiles->runScanner(Object(OC\\\\User\\\\User))\\n
#3 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/private\\\/BackgroundJob\\\/Job.php(52): OCA\\\\Files\\\\BackgroundJob\\\\ScanFiles->run(NULL)\\n
#4 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/private\\\/BackgroundJob\\\/TimedJob.php(53): OC\\\\BackgroundJob\\\\Job->execute(Object(OC\\\\BackgroundJob\\\\JobList), Object(OC\\\\Log))\\n
#5 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/cron.php(122): OC\\\\BackgroundJob\\\\TimedJob->execute(Object(OC\\\\BackgroundJob\\\\JobList), Object(OC\\\\Log))\\n
#6 {main}\",\"File\":\"\\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/private\\\/Files\\\/Cache\\\/Propagator.php\",\"Line\":145}","level":3,"time":"2016-07-18T07:00:01+00:00","method":"--","url":"--","user":"--"}
{"reqId":"bWfFLm+WCGs9gCLS9hJs","remoteAddr":"","app":"files","message":"Exception: {\"Exception\":\"BadMethodCallException\",\"Message\":\"Not in batch\",\"Code\":0,\"Trace\":\"
#0 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/private\\\/Files\\\/Utils\\\/Scanner.php(143): OC\\\\Files\\\\Cache\\\\Propagator->commitBatch()\\n
#1 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/apps\\\/files\\\/lib\\\/BackgroundJob\\\/ScanFiles.php(87): OC\\\\Files\\\\Utils\\\\Scanner->backgroundScan('')\\n
#2 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/apps\\\/files\\\/lib\\\/BackgroundJob\\\/ScanFiles.php(111): OCA\\\\Files\\\\BackgroundJob\\\\ScanFiles->runScanner(Object(OC\\\\User\\\\User))\\n
#3 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/private\\\/BackgroundJob\\\/Job.php(52): OCA\\\\Files\\\\BackgroundJob\\\\ScanFiles->run(NULL)\\n
#4 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/private\\\/BackgroundJob\\\/TimedJob.php(53): OC\\\\BackgroundJob\\\\Job->execute(Object(OC\\\\BackgroundJob\\\\JobList), Object(OC\\\\Log))\\n
#5 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/cron.php(122): OC\\\\BackgroundJob\\\\TimedJob->execute(Object(OC\\\\BackgroundJob\\\\JobList), Object(OC\\\\Log))\\n
#6 {main}\",\"File\":\"\\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/private\\\/Files\\\/Cache\\\/Propagator.php\",\"Line\":145}","level":3,"time":"2016-07-18T07:00:01+00:00","method":"--","url":"--","user":"--"}
{"reqId":"bWfFLm+WCGs9gCLS9hJs","remoteAddr":"","app":"files","message":"Exception: {\"Exception\":\"BadMethodCallException\",\"Message\":\"Not in batch\",\"Code\":0,\"Trace\":\"
#0 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/private\\\/Files\\\/Utils\\\/Scanner.php(143): OC\\\\Files\\\\Cache\\\\Propagator->commitBatch()\\n
#1 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/apps\\\/files\\\/lib\\\/BackgroundJob\\\/ScanFiles.php(87): OC\\\\Files\\\\Utils\\\\Scanner->backgroundScan('')\\n
#2 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/apps\\\/files\\\/lib\\\/BackgroundJob\\\/ScanFiles.php(111): OCA\\\\Files\\\\BackgroundJob\\\\ScanFiles->runScanner(Object(OC\\\\User\\\\User))\\n
#3 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/private\\\/BackgroundJob\\\/Job.php(52): OCA\\\\Files\\\\BackgroundJob\\\\ScanFiles->run(NULL)\\n
#4 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/private\\\/BackgroundJob\\\/TimedJob.php(53): OC\\\\BackgroundJob\\\\Job->execute(Object(OC\\\\BackgroundJob\\\\JobList), Object(OC\\\\Log))\\n
#5 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/cron.php(122): OC\\\\BackgroundJob\\\\TimedJob->execute(Object(OC\\\\BackgroundJob\\\\JobList), Object(OC\\\\Log))\\n
#6 {main}\",\"File\":\"\\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/private\\\/Files\\\/Cache\\\/Propagator.php\",\"Line\":145}","level":3,"time":"2016-07-18T07:00:01+00:00","method":"--","url":"--","user":"--"}
{"reqId":"bWfFLm+WCGs9gCLS9hJs","remoteAddr":"","app":"cron","message":"Finished job with ID 165","level":0,"time":"2016-07-18T07:00:01+00:00","method":"--","url":"--","user":"--"}
{"reqId":"bWfFLm+WCGs9gCLS9hJs","remoteAddr":"","app":"cron","message":"Run job with ID 166","level":0,"time":"2016-07-18T07:00:01+00:00","method":"--","url":"--","user":"--"}
{"reqId":"bWfFLm+WCGs9gCLS9hJs","remoteAddr":"","app":"cron","message":"Finished job with ID 166","level":0,"time":"2016-07-18T07:00:01+00:00","method":"--","url":"--","user":"--"}
{"reqId":"bWfFLm+WCGs9gCLS9hJs","remoteAddr":"","app":"cron","message":"Run job with ID 168","level":0,"time":"2016-07-18T07:00:01+00:00","method":"--","url":"--","user":"--"}
{"reqId":"bWfFLm+WCGs9gCLS9hJs","remoteAddr":"","app":"cron","message":"Finished job with ID 168","level":0,"time":"2016-07-18T07:00:01+00:00","method":"--","url":"--","user":"--"}
{"reqId":"bWfFLm+WCGs9gCLS9hJs","remoteAddr":"","app":"cron","message":"Run job with ID 181","level":0,"time":"2016-07-18T07:00:01+00:00","method":"--","url":"--","user":"--"}
{"reqId":"bWfFLm+WCGs9gCLS9hJs","remoteAddr":"","app":"cron","message":"Finished job with ID 181","level":0,"time":"2016-07-18T07:00:01+00:00","method":"--","url":"--","user":"--"}

Versions

ownCloud 9.1.0 RC2

@owncloud/filesystem

The text was updated successfully, but these errors were encountered:

PVince81 · 2016-07-18T08:03:14Z

ownCloud 9.1.0 RC2
apache2-2.4.10-28.1.x86_64
php5-5.6.1-69.1.x86_64
openSUSE 13.2 x86_64

PVince81 · 2016-07-18T08:09:20Z

I'll debug this later on my server. I have encryption enabled, in case it matters.

PVince81 · 2016-07-18T08:23:37Z

$CONFIG = array (
  'datadirectory' => '/srv/www/vhosts/owncloud/data',
  'dbtype' => 'mysql',
  'version' => '9.1.0.12',
  'installed' => true,
  'lastupdatedat' => '1335993186.8567',
  'instanceid' => 'REMOVED',
  'maintenance' => false,
  'theme' => '',
  'dbname' => 'REMOVED',
  'dbhost' => 'localhost',
  'dbtableprefix' => 'oc_',
  'dbuser' => 'REMOVED',
  'dbpassword' => 'REMOVED',
  'loglevel' => '0',
  'updatechecker' => false,
  'trusted_domains' => 
  array (
    0 => 'owncloud.vincentpetry.net',
  ),
  'secret' => 'REMOVED',
  'appcodechecker' => false,
  'filesystem_check_changes' => 0,
  'appstore.experimental.enabled' => true,
  'trashbin_retention_obligation' => 'auto',
  'overwrite.cli.url' => 'https://owncloud.vincentpetry.net/',
  'htaccess.RewriteBase' => '/',
);

PVince81 · 2016-07-18T08:29:48Z

A first glimpse seem to imply that it is impossible that we're not in "batch" mode: https://github.com/owncloud/core/blob/stable9.1/lib/private/Files/Utils/Scanner.php#L143

The beginBatch method would set the propagator in batch mode before scanning, then commit.

So it is likely that maybe the 'backgroundScan` method itself already committed the batch before.

PVince81 · 2016-07-18T08:33:14Z

I don't have any external storages, so I don't know why the cron background scanner is scanning anything at all

This is oc_storages:

MariaDB [owncloud]> select * from oc_storages;
+---------------------------------------+------------+-----------+--------------+
| id                                    | numeric_id | available | last_checked |
+---------------------------------------+------------+-----------+--------------+
| home::vincent                         |          1 |         1 |         NULL |
| home::user1                        |          2 |         1 |         NULL |
| home::user2                       |          3 |         1 |         NULL |
| home::user3                        |          4 |         1 |         NULL |
| local::/srv/www/vhosts/owncloud/data/ |          5 |         1 |         NULL |
| shared::/User1/QA                  |          6 |         1 |         NULL |
| shared::/User1/usrguide.tex        |          7 |         1 |         NULL |
| shared::/petry                        |          8 |         1 |         NULL |
| shared::/Test_VP                      |          9 |         1 |         NULL |
| shared::/Shared/user2             |         10 |         1 |         NULL |
+---------------------------------------+------------+-----------+--------------+

Apart from some suspicious "shared::" entries, it looks fine. (#24106).

I don't have any federated shares (fed sharing is disabled completely).

Let's add a few log statements...

PVince81 · 2016-07-18T08:47:03Z

Ok, I added some logging and every time I run cron it tries to scan one of the bogus "shared::" entries.
We need to get rid of those at some point: #24106

These storages are completely empty and have no matching filecache entries, but it doesn't explain why it throws that exception.

PVince81 · 2016-07-18T09:10:53Z

Ok, the bogus storages bug is fixed in 9.1.0RC2, however I still have entries from older versions.

This inBatch thing doesn't make any sense at all!

{"reqId":"dQqk0IbSizEziwFDe4Kw","remoteAddr":"","app":"DEBUG","message":"before beginBatch: storage id=shared::\/petry","level":3,"time":"2016-07-18T09:09:01+00:00","method":"--","url":"--","user":"--"}
{"reqId":"dQqk0IbSizEziwFDe4Kw","remoteAddr":"","app":"DEBUG","message":"Propagator: constructor, with storage idshared::\/petry","level":0,"time":"2016-07-18T09:09:01+00:00","method":"--","url":"--","user":"--"}
{"reqId":"dQqk0IbSizEziwFDe4Kw","remoteAddr":"","app":"DEBUG","message":"Propagator: beginBatch","level":0,"time":"2016-07-18T09:09:01+00:00","method":"--","url":"--","user":"--"}
{"reqId":"dQqk0IbSizEziwFDe4Kw","remoteAddr":"","app":"DEBUG","message":"Propagator: beginBatch inBatch=1","level":0,"time":"2016-07-18T09:09:01+00:00","method":"--","url":"--","user":"--"}
{"reqId":"dQqk0IbSizEziwFDe4Kw","remoteAddr":"","app":"DEBUG","message":"backgroundScan","level":0,"time":"2016-07-18T09:09:01+00:00","method":"--","url":"--","user":"--"}
{"reqId":"dQqk0IbSizEziwFDe4Kw","remoteAddr":"","app":"DEBUG","message":"backgroundScan yes inCache","level":0,"time":"2016-07-18T09:09:01+00:00","method":"--","url":"--","user":"--"}
{"reqId":"dQqk0IbSizEziwFDe4Kw","remoteAddr":"","app":"DEBUG","message":"Propagator: constructor, with storage idshared::\/petry","level":0,"time":"2016-07-18T09:09:01+00:00","method":"--","url":"--","user":"--"}
{"reqId":"dQqk0IbSizEziwFDe4Kw","remoteAddr":"","app":"DEBUG","message":"Propagator: commitBatch BEGIN","level":0,"time":"2016-07-18T09:09:01+00:00","method":"--","url":"--","user":"--"}
{"reqId":"dQqk0IbSizEziwFDe4Kw","remoteAddr":"","app":"DEBUG","message":"Propagator: commitBatch inBatch=","level":0,"time":"2016-07-18T09:09:01+00:00","method":"--","url":"--","user":"--"}
{"reqId":"dQqk0IbSizEziwFDe4Kw","remoteAddr":"","app":"files","message":"Exception: {\"Exception\":\"BadMethodCallException\",\"Message\":\"Not in batch\",\"Code\":0,\"Trace\":\"#0 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/private\\\/Files\\\/Utils\\\/Scanner.php(145): OC\\\\Files\\\\Cache\\\\Propagator->commitBatch()\\n#1 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/apps\\\/files\\\/lib\\\/BackgroundJob\\\/ScanFiles.php(87): OC\\\\Files\\\\Utils\\\\Scanner->backgroundScan('')\\n#2 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/apps\\\/files\\\/lib\\\/BackgroundJob\\\/ScanFiles.php(111): OCA\\\\Files\\\\BackgroundJob\\\\ScanFiles->runScanner(Object(OC\\\\User\\\\User))\\n#3 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/private\\\/BackgroundJob\\\/Job.php(52): OCA\\\\Files\\\\BackgroundJob\\\\ScanFiles->run(NULL)\\n#4 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/private\\\/BackgroundJob\\\/TimedJob.php(53): OC\\\\BackgroundJob\\\\Job->execute(Object(OC\\\\BackgroundJob\\\\JobList), Object(OC\\\\Log))\\n#5 \\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/cron.php(122): OC\\\\BackgroundJob\\\\TimedJob->execute(Object(OC\\\\BackgroundJob\\\\JobList), Object(OC\\\\Log))\\n#6 {main}\",\"File\":\"\\\/srv\\\/www\\\/htdocs\\\/owncloud\\\/lib\\\/private\\\/Files\\\/Cache\\\/Propagator.php\",\"Line\":152}","level":3,"time":"2016-07-18T09:09:01+00:00","method":"--","url":"--","user":"--"}

When calling beginBatch it does set inBatch to true (1).
The only code that sets it back to false is commitBatch, however that method is never called before the commitBatch that fails. And that this stage, inBatch is suddenly empty ?!

PVince81 · 2016-07-18T09:26:17Z

Okay, found it: if you look closely at https://github.com/owncloud/core/blob/stable9.1/lib/private/Files/Utils/Scanner.php#L143

You can see that for both calls it calls getPropagator() before chaining to beginBatch and commitBatch.

The Shared storage's getPropagator() method doesn't cache it, so it recreates a brand new instance where beginBatch is not set for obvious reasons...

Two solutions:

Fix SharedStorage to cache its propagator instance
Make the background scanner store the $storage instance before calling commit on it.

PVince81 · 2016-07-18T09:39:44Z

Steps to reproduce:

Check out v9.0.3
Do the steps from Bogus shared:: storage entry in oc_storages #24106 to create bogus "shared::" storage instances
Update to 9.1.0RC2 (where the batching was implemented)
Run cron (make sure the Background scan one runs)

PVince81 · 2016-07-18T09:40:29Z

PR here #25509

PVince81 · 2016-07-22T10:29:25Z

This was observed also by giacomo1989 on IRC when running a file:scan.

Same steps as #24106 but run "occ files:scan --all" instead of cron.

petry:/srv/www/htdocs/owncloud # sudo -u wwwrun ./occ files:scan --all
The process control (PCNTL) extensions are required in case you want to interrupt long running commands - see http://php.net/manual/en/book.pcntl.php

Scanning files for 3 users
Starting scan for user 1 out of 3 (admin)
Starting scan for user 2 out of 3 (user1)
Starting scan for user 3 out of 3 (user2)
Exception while scanning: Not in batch
#0 /srv/www/htdocs/owncloud/lib/private/Files/Utils/Scanner.php(199): OC\Files\Cache\Propagator->commitBatch()
#1 /srv/www/htdocs/owncloud/apps/files/lib/Command/Scan.php(155): OC\Files\Utils\Scanner->scan('/user2')
#2 /srv/www/htdocs/owncloud/apps/files/lib/Command/Scan.php(223): OCA\Files\Command\Scan->scanFiles('user2', '/user2', false, Object(Symfony\Component\Console\Output\ConsoleOutput), false)
#3 /srv/www/htdocs/owncloud/3rdparty/symfony/console/Command/Command.php(259): OCA\Files\Command\Scan->execute(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#4 /srv/www/htdocs/owncloud/core/Command/Base.php(158): Symfony\Component\Console\Command\Command->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#5 /srv/www/htdocs/owncloud/3rdparty/symfony/console/Application.php(844): OC\Core\Command\Base->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#6 /srv/www/htdocs/owncloud/3rdparty/symfony/console/Application.php(192): Symfony\Component\Console\Application->doRunCommand(Object(OCA\Files\Command\Scan), Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#7 /srv/www/htdocs/owncloud/3rdparty/symfony/console/Application.php(123): Symfony\Component\Console\Application->doRun(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#8 /srv/www/htdocs/owncloud/lib/private/Console/Application.php(146): Symfony\Component\Console\Application->run(NULL, NULL)
#9 /srv/www/htdocs/owncloud/console.php(94): OC\Console\Application->run()
#10 /srv/www/htdocs/owncloud/occ(11): require_once('/srv/www/htdocs...')
#11 {main}

Raising severity as occ files:scan is used as workaround for many problems.

TheGrave-zz · 2016-07-23T03:58:38Z

Similar story here on 9.1.0.15 when running php console.php files:scan --all:


Exception while scanning: Not in batch
#0 /var/www/owncloud/lib/private/Files/Utils/Scanner.php(199): OC\Files\Cache\Propagator->commitBatch()
#1 /var/www/owncloud/apps/files/lib/Command/Scan.php(155): OC\Files\Utils\Scanner->scan('/TestUser')
#2 /var/www/owncloud/apps/files/lib/Command/Scan.php(223): OCA\Files\Command\Scan->scanFiles('TestUser', '/TestUser', false, Object(Symfony\Component\Console\Output\ConsoleOutput), false)
#3 /var/www/owncloud/3rdparty/symfony/console/Command/Command.php(259): OCA\Files\Command\Scan->execute(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#4 /var/www/owncloud/core/Command/Base.php(158): Symfony\Component\Console\Command\Command->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#5 /var/www/owncloud/3rdparty/symfony/console/Application.php(844): OC\Core\Command\Base->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#6 /var/www/owncloud/3rdparty/symfony/console/Application.php(192): Symfony\Component\Console\Application->doRunCommand(Object(OCA\Files\Command\Scan), Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#7 /var/www/owncloud/3rdparty/symfony/console/Application.php(123): Symfony\Component\Console\Application->doRun(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#8 /var/www/owncloud/lib/private/Console/Application.php(146): Symfony\Component\Console\Application->run(NULL, NULL)
#9 /var/www/owncloud/console.php(94): OC\Console\Application->run()
#10 {main}

I also get some "Home storage for user TestUser not writable" errors which make no sense - I made sure all files in OwnCloud data dir get www-data:www-data set as owner recursively.

bjoernv · 2016-07-23T14:06:19Z

After applying the pull request, the "Exception while scanning: Not in batch" exception disappears. But at the end of scanning with

./occ files:scan -vvv username123

I get

        File   /username123/thumbnails/180/36-36.png
Home storage for user username123 not writable
Make sure you're running the scan command only as the user the web server runs as

The message is incorrect. "occ" runs as user www-data and data/username123 and the sub directories are writable by www-data.

ghost · 2016-07-29T11:06:30Z

same issue :(

jhquentin · 2016-07-29T19:16:58Z

same issue :-(
ownCloud version 9.1.0

php occ files:scan terezka.smekalova
Starting scan for user 1 out of 1 (terezka.smekalova)
Exception while scanning: Not in batch
#0 /var/www/owncloud/lib/private/Files/Utils/Scanner.php(199): OC\Files\Cache\Propagator->commitBatch()
#1 /var/www/owncloud/apps/files/lib/Command/Scan.php(155): OC\Files\Utils\Scanner->scan('/terezka.smekal...')
#2 /var/www/owncloud/apps/files/lib/Command/Scan.php(223): OCA\Files\Command\Scan->scanFiles('terezka.smekalo...', '/terezka.smekal...', false, Object(Symfony\Component\Console\Output\ConsoleOutput), false)
#3 /var/www/owncloud/3rdparty/symfony/console/Command/Command.php(259): OCA\Files\Command\Scan->execute(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#4 /var/www/owncloud/core/Command/Base.php(158): Symfony\Component\Console\Command\Command->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#5 /var/www/owncloud/3rdparty/symfony/console/Application.php(844): OC\Core\Command\Base->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#6 /var/www/owncloud/3rdparty/symfony/console/Application.php(192): Symfony\Component\Console\Application->doRunCommand(Object(OCA\Files\Command\Scan), Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#7 /var/www/owncloud/3rdparty/symfony/console/Application.php(123): Symfony\Component\Console\Application->doRun(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#8 /var/www/owncloud/lib/private/Console/Application.php(146): Symfony\Component\Console\Application->run(NULL, NULL)
#9 /var/www/owncloud/console.php(94): OC\Console\Application->run()
#10 /var/www/owncloud/occ(11): require_once('/var/www/ownclo...')
#11 {main}

+---------+-------+--------------+
| Folders | Files | Elapsed time |
+---------+-------+--------------+
| 5 | 6 | 00:00:08 |
+---------+-------+--------------+

zenlord · 2016-08-02T15:09:25Z

I am also affected.
Debian 8 Jessie with Owncloud 9.1 from official ownCloud repo.

poldixd · 2016-08-03T12:43:16Z

Same issue on three owncloud instances:

Debian 7.11‬ php7.0

version: 9.1.0.15
versionstring: 9.1.0

$ /opt/plesk/php/7.0/bin/php occ files:scan --all

Starting scan for user 1 out of 20 (USERNAME)
Exception while scanning: Not in batch
#0 /var/www/vhosts/OWNCLOUD_INSTANZ/httpdocs/owncloud/lib/private/Files/Utils/Scanner.php(199): OC\Files\Cache\Propagator->commitBatch()
#1 /var/www/vhosts/OWNCLOUD_INSTANZ/httpdocs/owncloud/apps/files/lib/Command/Scan.php(155): OC\Files\Utils\Scanner->scan('/USERNAME...')
#2 /var/www/vhosts/OWNCLOUD_INSTANZ/httpdocs/owncloud/apps/files/lib/Command/Scan.php(223): OCA\Files\Command\Scan->scanFiles('USERNAME...', '/USERNAME...', false, Object(Symfony\Component\Console\Output\ConsoleOutput), false)
#3 /var/www/vhosts/OWNCLOUD_INSTANZ/httpdocs/owncloud/3rdparty/symfony/console/Command/Command.php(259): OCA\Files\Command\Scan->execute(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#4 /var/www/vhosts/OWNCLOUD_INSTANZ/httpdocs/owncloud/core/Command/Base.php(158): Symfony\Component\Console\Command\Command->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#5 /var/www/vhosts/OWNCLOUD_INSTANZ/httpdocs/owncloud/3rdparty/symfony/console/Application.php(844): OC\Core\Command\Base->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#6 /var/www/vhosts/OWNCLOUD_INSTANZ/httpdocs/owncloud/3rdparty/symfony/console/Application.php(192): Symfony\Component\Console\Application->doRunCommand(Object(OCA\Files\Command\Scan), Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#7 /var/www/vhosts/OWNCLOUD_INSTANZ/httpdocs/owncloud/3rdparty/symfony/console/Application.php(123): Symfony\Component\Console\Application->doRun(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#8 /var/www/vhosts/OWNCLOUD_INSTANZ/httpdocs/owncloud/lib/private/Console/Application.php(146): Symfony\Component\Console\Application->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#9 /var/www/vhosts/OWNCLOUD_INSTANZ/httpdocs/owncloud/console.php(94): OC\Console\Application->run()
#10 /var/www/vhosts/OWNCLOUD_INSTANZ/httpdocs/owncloud/occ(11): require_once('/var/www/vhosts...')
#11 {main}

Shared Hoster Ubuntu 14.04.4 LTS‬ php7.0 CGI

version: 9.1.0.15
versionstring: 9.1.0

$ php occ files:scan --all

Starting scan for user 1 out of 7 (USERNAME)
Exception while scanning: Not in batch
#0 /www/htdocs/OWNCLOUD_INSTANZ/owncloud/lib/private/Files/Utils/Scanner.php(199): OC\Files\Cache\Propagator->commitBatch()
#1 /www/htdocs/OWNCLOUD_INSTANZ/owncloud/apps/files/lib/Command/Scan.php(155): OC\Files\Utils\Scanner->scan('/USERNAME')
#2 /www/htdocs/OWNCLOUD_INSTANZ/owncloud/apps/files/lib/Command/Scan.php(223): OCA\Files\Command\Scan->scanFiles('USERNAME', '/USERNAME', false, Object(Symfony\Component\Console\Output\ConsoleOutput), false)
#3 /www/htdocs/OWNCLOUD_INSTANZ/owncloud/3rdparty/symfony/console/Command/Command.php(259): OCA\Files\Command\Scan->execute(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#4 /www/htdocs/OWNCLOUD_INSTANZ/owncloud/core/Command/Base.php(158): Symfony\Component\Console\Command\Command->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#5 /www/htdocs/OWNCLOUD_INSTANZ/owncloud/3rdparty/symfony/console/Application.php(844): OC\Core\Command\Base->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#6 /www/htdocs/OWNCLOUD_INSTANZ/owncloud/3rdparty/symfony/console/Application.php(192): Symfony\Component\Console\Application->doRunCommand(Object(OCA\Files\Command\Scan), Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#7 /www/htdocs/OWNCLOUD_INSTANZ/owncloud/3rdparty/symfony/console/Application.php(123): Symfony\Component\Console\Application->doRun(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#8 /www/htdocs/OWNCLOUD_INSTANZ/owncloud/lib/private/Console/Application.php(146): Symfony\Component\Console\Application->run(NULL, NULL)
#9 /www/htdocs/OWNCLOUD_INSTANZ/owncloud/console.php(94): OC\Console\Application->run()
#10 /www/htdocs/OWNCLOUD_INSTANZ/owncloud/occ(11): require_once('/www/htdocs/w01...')
#11 {main}

anduz · 2016-08-03T13:04:04Z

Also had this issue, went back to 9.0.2 restoring a backup, now it seems to work
"Exception while scanning: Not in batch"
On the desktop clients then it downloaded all the files again

Cardes · 2016-08-03T13:15:09Z

Same here

Ubuntu 16.04.1 LTS, Apache/2.4.18, PHP 7.0.8-0ubuntu0.16.04.2

"system": {
    "instanceid": "51ea54e1a26bf",
    "passwordsalt": "***REMOVED SENSITIVE VALUE***",
    "datadirectory": "\/var\/data",
    "dbtype": "mysql",
    "version": "9.1.0.15",
    "installed": true,
    "theme": "",
    "maintenance": false,
    "loglevel": 1,
    "logfile": "\/var\/data\/owncloud.log",
    "logtimezone": "Europe\/Berlin",
    "log_authfailip": true,
    "forcessl": true,
    "mail_smtpmode": "sendmail",
    "mail_smtphost": "mail.vaduzz.de",
    "mail_smtpport": "587",
    "mail_smtpsecure": "tls",
    "mail_smtpauth": 1,
    "mail_smtpauthtype": "PLAIN",
    "mail_smtpname": "***REMOVED SENSITIVE VALUE***",
    "mail_smtppassword": "***REMOVED SENSITIVE VALUE***",
    "memcache.local": "\\OC\\Memcache\\Redis",
    "redis": {
        "host": "localhost",
        "port": 6379
    },
    "memcache.locking": "\\OC\\Memcache\\Redis",
    "trusted_domains": [
        "cloud.vaduzz.de",
        "v.house-of-loops.de",
        "vaduzz.de"
    ],
    "mail_from_address": "no-reply",
    "mail_domain": "vaduzz.de",
    "secret": "***REMOVED SENSITIVE VALUE***",
    "dbname": "owncloud",
    "dbhost": "localhost",
    "dbuser": "***REMOVED SENSITIVE VALUE***",
    "dbpassword": "***REMOVED SENSITIVE VALUE***",
    "trashbin_retention_obligation": "auto",
    "updatechecker": false,
    "updater.server.url": "https:\/\/updates.owncloud.com\/server\/",
    "appcodechecker": true,
    "versions_retention_obligation": "auto",
    "check_for_working_webdav": true,
    "check_for_working_wellknown_setup": true,
    "check_for_working_htaccess": true,
    "appstoreenabled": true,
    "appstoreurl": "https:\/\/api.owncloud.com\/v1",
    "apps_paths": [
        {
            "path": "\/var\/www\/owncloud\/apps",
            "url": "\/apps",
            "writable": true
        }
    ],
    "filesystem_check_changes": 0

sudo -u www-data php /var/www/owncloud/occ files:scan user1

Starting scan for user 1 out of 1 (user1)
Exception while scanning: Not in batch

#0 /var/www/owncloud/lib/private/Files/Utils/Scanner.php(199): OC\Files\Cache\Propagator->commitBatch()
#1 /var/www/owncloud/apps/files/lib/Command/Scan.php(155): OC\Files\Utils\Scanner->scan('/user1')
#2 /var/www/owncloud/apps/files/lib/Command/Scan.php(223): OCA\Files\Command\Scan->scanFiles('user1', '/user1', false, Object(Symfony\Component\Console\Output\ConsoleOutput), false)
#3 /var/www/owncloud/3rdparty/symfony/console/Command/Command.php(259): OCA\Files\Command\Scan->execute(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#4 /var/www/owncloud/core/Command/Base.php(158): Symfony\Component\Console\Command\Command->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#5 /var/www/owncloud/3rdparty/symfony/console/Application.php(844): OC\Core\Command\Base->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#6 /var/www/owncloud/3rdparty/symfony/console/Application.php(192): Symfony\Component\Console\Application->doRunCommand(Object(OCA\Files\Command\Scan), Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#7 /var/www/owncloud/3rdparty/symfony/console/Application.php(123): Symfony\Component\Console\Application->doRun(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#8 /var/www/owncloud/lib/private/Console/Application.php(146): Symfony\Component\Console\Application->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
#9 /var/www/owncloud/console.php(94): OC\Console\Application->run()
#10 /var/www/owncloud/occ(11): require_once('/var/www/ownclo...')
#11 {main}

Also for some other user i get

sudo -u www-data php /var/www/owncloud/occ files:scan user2
Starting scan for user 1 out of 1 (user2)
Home storage for user user2 not writable
Make sure you're running the scan command only as the user the web server runs as

Permissions are the same, is there any lock in the database possibly doing this?

jhquentin · 2016-08-03T13:49:12Z

What about database, when downgrading.
You did restore everything from backup?
Jan Hladík
jan.hladik@iquentin.cz
+420 603324153
Odesláno z Android

On 3 Aug 2016, anduz notifications@github.com wrote:

Also had this issue, went back to 9.0.2 restoring a backup, now it
seems to work
"Exception while scanning: Not in batch"
On the desktop clients then it downloaded all the files again

You are receiving this because you commented.
Reply to this email directly or view it on GitHub:
#25506 (comment)

tuxmaster · 2016-08-06T08:54:51Z

The same error using CentOS 7 with the default php installation.
But not all users are affect. I can't see any suspected entry in the database.

kontaxis · 2016-08-07T14:42:00Z

This looks similar to #25611

Cardes · 2016-08-07T17:45:19Z

Kontaxis:
It may be related but its somewhat different because i have users with shares but without these errors and also users with shares and with errors.

PVince81 · 2016-08-08T07:18:13Z

For all of you having "BadMethodCallException", can you try with #25509 ?

Regarding the "home storage not writable" it is likely a separate issue, but it would be good to see if anyone else is getting it too after applying the patch.

Thanks!

schnello · 2016-08-09T19:27:58Z

@PVince81 What is the min requirement for this pr? If i add the two files i get only an internal server error.

root@uplink:/var/www/owncloud# sudo -u www-data php occ -V
ownCloud version 9.1.0
Ubuntu Server 16.04

Flachzange · 2016-08-09T19:31:28Z

@schnello You should only make the changes mentioned. If you swap the whole files than you're mixing versions (9.1.0 vs. master). That's likely causing the internal server error

For me, the fix has the desired effect. Thx

schnello · 2016-08-09T19:33:10Z

@Flachzange

Thanks for this hint. I try to add only the changes.

Edit:
Thanks. Works fine

Regarding the "home storage not writable" it is likely a separate issue, but it would be good to see if anyone else is getting it too after applying the patch.

Can confirm. I have now the same "error" message

PVince81 · 2016-08-10T06:40:16Z

Thanks for the feedback.

@schnello please raise a separate ticket about "home storage not writable" if you're sure that the permissions are already correct.

schnello · 2016-08-10T08:43:56Z

@PVince81
Done with #25755

Thank again for the #PR25509

again002 · 2016-08-11T21:34:59Z

How i can repair my owncloud:
"Exception while scanning: Not in batch"
""message":"Exception: {"Exception":"BadMethodCallException""

$OC_Version = array(9,1,0,15);
$OC_VersionString = '9.1.0';

schnello · 2016-08-12T06:44:27Z

Hello @again002

Two ways:

Clone the owncloud core git, checkout the PR25509, create a patch related to the PR and add the patch to "apps/files_sharing/lib/sharedstorage.php" and "lib/private/Files/Utils/Scanner.php"

2). You can try my patched files (9.1.0.15). Please dont forget to make a copy of your original files:
PR25509_Owncloud.zip

PVince81 · 2016-08-12T07:48:47Z

Or you can download the PR directly as patch by appending ".patch": https://github.com/owncloud/core/pull/25751.patch

jhquentin · 2016-08-12T10:06:42Z

patch is working for me,
thank you for quick resolution

again002 · 2016-08-12T10:07:47Z

Yes, patch is working.
Thanks ;)

Thomanji · 2016-08-17T05:35:28Z

Yes, working for me as well.
However now I also get the "Home storage for user xxxx not writable" error after applying.

sudo -u apache php occ files:scan --all
Home storage for user xxxx not writable
Make sure you're running the scan command only as the user the web server runs as

No permissions where changed. and all files are owner by apache and are 755.
Lest see if ticket #25755 will resolve it.

tuxmaster · 2016-08-18T07:40:08Z

works.Thanks.

scysys · 2016-09-17T14:25:50Z

Have the same issue and the Patch is working, thanks.

lock · 2019-08-03T15:01:08Z

This thread has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.

PVince81 added Type:Bug comp:filesystem labels Jul 18, 2016

PVince81 added this to the 9.1.1 milestone Jul 18, 2016

PVince81 self-assigned this Jul 18, 2016

PVince81 mentioned this issue Jul 18, 2016

Store the shared propagator instance #25509

Merged

PVince81 added regression sev2-high labels Jul 22, 2016

DeepDiver1975 mentioned this issue Aug 2, 2016

Strange errors about Scanner.php and Propagator.php #25681

Closed

This was referenced Aug 8, 2016

File Sharing stack overflow, memory issue, crash, CSRF issue on 9.1.0 #25557

Closed

After update from 9.0.4 to 9.1 occ files:scall --all does not work correctly. #25611

Closed

PVince81 mentioned this issue Aug 10, 2016

[stable9.1] Store the shared propagator instance #25751

Merged

DeepDiver1975 closed this as completed in #25509 Aug 12, 2016

PVince81 mentioned this issue Aug 31, 2016

9.1 stable Federated share not longer available (storage not available) #25854

Closed

MrJackJonesIII mentioned this issue Sep 19, 2016

[SMB External Storage] Some big files being corrupted when downloaded #26155

Closed

caguiar mentioned this issue Sep 29, 2016

webdav login isn't working for CIFS share with "session credentials" in OC 9.0.0 #23756

Closed

caguiar mentioned this issue Oct 20, 2016

Sync client does not work when /data directory is a CIFS mount #14769

Closed

lock bot locked as resolved and limited conversation to collaborators Aug 3, 2019

BadMethodCallException in scanner from cron #25506

BadMethodCallException in scanner from cron #25506

Comments

PVince81 commented Jul 18, 2016

Steps

Logs

Versions

PVince81 commented Jul 18, 2016

PVince81 commented Jul 18, 2016

PVince81 commented Jul 18, 2016

PVince81 commented Jul 18, 2016

PVince81 commented Jul 18, 2016

PVince81 commented Jul 18, 2016

PVince81 commented Jul 18, 2016

PVince81 commented Jul 18, 2016

PVince81 commented Jul 18, 2016

PVince81 commented Jul 18, 2016

PVince81 commented Jul 22, 2016

TheGrave-zz commented Jul 23, 2016

bjoernv commented Jul 23, 2016 • edited Loading

ghost commented Jul 29, 2016

jhquentin commented Jul 29, 2016

zenlord commented Aug 2, 2016

poldixd commented Aug 3, 2016

anduz commented Aug 3, 2016

Cardes commented Aug 3, 2016

jhquentin commented Aug 3, 2016

tuxmaster commented Aug 6, 2016

kontaxis commented Aug 7, 2016

Cardes commented Aug 7, 2016

PVince81 commented Aug 8, 2016

schnello commented Aug 9, 2016

Flachzange commented Aug 9, 2016 • edited Loading

schnello commented Aug 9, 2016 • edited Loading

PVince81 commented Aug 10, 2016

schnello commented Aug 10, 2016

again002 commented Aug 11, 2016

schnello commented Aug 12, 2016 • edited Loading

PVince81 commented Aug 12, 2016

jhquentin commented Aug 12, 2016

again002 commented Aug 12, 2016

Thomanji commented Aug 17, 2016

tuxmaster commented Aug 18, 2016

scysys commented Sep 17, 2016

lock bot commented Aug 3, 2019

bjoernv commented Jul 23, 2016 •

edited

Loading

Flachzange commented Aug 9, 2016 •

edited

Loading

schnello commented Aug 9, 2016 •

edited

Loading

schnello commented Aug 12, 2016 •

edited

Loading