Update leads to error 500 on step 11 (continue with web based installer)

[caco3]

Note: This issue might only be related to hostpoint.ch installations.

Until the fix #508 it was not possible at all to use the updater on hostpoint.ch installations. After the mentioned fix, the update successes until step 11:

But that step (disabling the maintenance mode) leads to an error 500:

Internal Server Error

The server encountered an internal error and was unable to complete your request.
Please contact the server administrator if this error reappears multiple times, please include the technical details below in your report.
More details can be found in the webserver log.

[caco3]

Webserver log:

[Wed Oct 25 23:22:47.604416 2023] [-:error] [pid 75959:tid 35145515008] [client 81.6.11.94:56114] FastCGI: server "/var/run/hcgi/243526" stderr: PHP Warning:  require(/home/xxx/www/xxx/nc-test/nc-normal/3rdparty/composer/../thecodingmachine/safe/generated/misc.php) [<a href='https://secure.php.net/manual/en/function.require.php'>function.require.php</a>]: Failed to open stream: No such file or directory in /home/xxx/www/xxx/nc-test/nc-normal/3rdparty/composer/autoload_real.php on line 46
[Wed Oct 25 23:22:47.604502 2023] [-:error] [pid 75959:tid 35145515008] [client 81.6.11.94:56114] FastCGI: server "/var/run/hcgi/243526" stderr: PHP Fatal error:  Uncaught Error: Failed opening required '/home/xxx/www/xxx/nc-test/nc-normal/3rdparty/composer/../thecodingmachine/safe/generated/misc.php' (include_path='/home/xxx/www/xxx/nc-test/nc-normal/3rdparty/pear/archive_tar:/home/xxx/www/xxx/nc-test/nc-normal/3rdparty/pear/console_getopt:/home/xxx/www/xxx/nc-test/nc-normal/3rdparty/pear/pear-core-minimal/src:/home/xxx/www/xxx/nc-test/nc-normal/3rdparty/pear/pear_exception:/home/xxx/www/xxx/nc-test/nc-normal/apps') in /home/xxx/www/xxx/nc-test/nc-normal/3rdparty/composer/autoload_real.php:46
[Wed Oct 25 23:22:47.604518 2023] [-:error] [pid 75959:tid 35145515008] [client 81.6.11.94:56114] FastCGI: server "/var/run/hcgi/243526" stderr: Stack trace:
[Wed Oct 25 23:22:47.604528 2023] [-:error] [pid 75959:tid 35145515008] [client 81.6.11.94:56114] FastCGI: server "/var/run/hcgi/243526" stderr: #0 /home/xxx/www/xxx/nc-test/nc-normal/3rdparty/composer/autoload_real.php(50): {closure}('98de16b8db03eb0...', '/home/xxx/...')
[Wed Oct 25 23:22:47.604538 2023] [-:error] [pid 75959:tid 35145515008] [client 81.6.11.94:56114] FastCGI: server "/var/run/hcgi/243526" stderr: #1 /home/xxx/www/xxx/nc-test/nc-normal/3rdparty/autoload.php(25): ComposerAutoloaderInit2f23f73bc0cc116b4b1eee1521aa8652::getLoader()
[Wed Oct 25 23:22:47.604548 2023] [-:error] [pid 75959:tid 35145515008] [client 81.6.11.94:56114] FastCGI: server "/var/run/hcgi/243526" stderr: #2 /home/xxx/www/xxx/nc-test/nc-normal/lib/base.php(618): require_once('/home/xxx/...')
[Wed Oct 25 23:22:47.604558 2023] [-:error] [pid 75959:tid 35145515008] [client 81.6.11.94:56114] FastCGI: server "/var/run/hcgi/243526" stderr: #3 /home/xxx/www/xxx/nc-test/nc-normal/lib/base.php(1173): OC::init()
[Wed Oct 25 23:22:47.604568 2023] [-:error] [pid 75959:tid 35145515008] [client 81.6.11.94:56114] FastCGI: server "/var/run/hcgi/243526" stderr: #4 /home/xxx/www/xxx/nc-test/nc-normal/index.php(34): require_once('/home/xxx/...')

The issue seems to be that several files are missing. How ever looking on the updater log, there is no error!

[caco3]

I do not yet understand what is going wrong. It seams that the moveWithExclusions() does not copy all files. For example, for lib/i10n it is supposed to copy 200 files, but always only 107 get copied:

It looks like as if the getRecursiveDirectoryIterator() does not return the full file list 😒

[caco3]

some updated information:
The iterator returns the right list of files, eg. 200 for the lib/i10n, as long as I do not modify the source directory.
How ever, the updater does a rename() to move the files. This seems to mess up the iterator list.

If I use copy() instead of rename(), we can workaround this issue!
And also the deletion must be run in a separate iteration.

See #511 for a Fix.

[joshtrichards]

These issues with the iterator - sound a bit like this:

nextcloud/server#17980 (comment)

(search for "RecursiveDirectoryIterator" to find the paragraph where it gets interesting).

[caco3]

@joshtrichards I do not think that this issue is related for following reasons:

1. My NC instance is not running inside a docker container. It runs on a shared server of hostpoint.ch and I believe the used BSD runs natively.
2. To my understanding, everything is located on the same drive.
3. Despite initial thoughts, getRecursiveDirectoryIterator() works as expected, it returns a list of all files. I proved this by only using it to output a list of all files:

   foreach ($this->getRecursiveDirectoryIterator($dataLocation) as $path => $fileInfo) {
   		$this->silentLog('[info] File: ' . explode($dataLocation, $path)[1]);
       }

   On the example of lib/i10n, all 200 files got listed.
   How ever, the updater actually alter (moves) the files within the foreach loop, causing that only 107 files get moved/listed.
   I have not found any information that such code is illegal, but when I changed the rename() with a copy() and therefore not altering the src folder, it worked as needed.
   Further down in the code, the loop also deletes the src folders. This again caused complete folders to be missing (not getting created/copied). How ever, when I splitted the copy and the delete task into separate iterations, the spooky behaviour went away...
4. The mentioned issue references issues when more than 62 files get processed. How ever the Updater moves or deletes each file separately.

[caco3]

I was now even able to create a minimalistic example which shows the breakage of the iterator.

PoC

<?php

function getRecursiveDirectoryIterator(?string $folder = null): \RecursiveIteratorIterator {
        return new \RecursiveIteratorIterator(
                new \RecursiveDirectoryIterator($folder, \RecursiveDirectoryIterator::SKIP_DOTS),
                \RecursiveIteratorIterator::CHILD_FIRST
        );
}


$i = 0;

mkdir("a");
mkdir("a/l10n");

foreach (getRecursiveDirectoryIterator("l10n") as $path) {
        $i++;
        $newPath = "a/" . $path;
        echo("$i: $path -> $newPath<br>\n");
//         rename($path, $newPath);             // <- makes the iterator to break
}

?>

Test 1 (rename() commented out)

The script lists all 200 files of the l10n folder:

1: l10n/af.js -> a/l10n/af.js
2: l10n/af.json -> a/l10n/af.json
3: l10n/an.js -> a/l10n/an.js
4: l10n/an.json -> a/l10n/an.json
5: l10n/ar.js -> a/l10n/ar.js
6: l10n/ar.json -> a/l10n/ar.json
[..]
198: l10n/zh_HK.json -> a/l10n/zh_HK.json
199: l10n/zh_TW.js -> a/l10n/zh_TW.js
200: l10n/zh_TW.json -> a/l10n/zh_TW.json
EOF

Test 2 (rename() active)

The script lists/moves only 106 files of the 200 files in the l10n folder:

1: l10n/af.js -> a/l10n/af.js
2: l10n/af.json -> a/l10n/af.json
3: l10n/an.js -> a/l10n/an.js
4: l10n/an.json -> a/l10n/an.json
5: l10n/ar.js -> a/l10n/ar.js
6: l10n/ar.json -> a/l10n/ar.json
[..]
104: l10n/zh_HK.json -> a/l10n/zh_HK.json
105: l10n/zh_TW.js -> a/l10n/zh_TW.js
106: l10n/zh_TW.json -> a/l10n/zh_TW.json
EOF

See https://docs.google.com/spreadsheets/d/1ATS0hoaB9s3xEsshpwEiY1RZs2o5wvQUxbthC3n9QKI/edit?usp=sharing for the collected data.
Interestingly, it iterates over the first 88 files, then misses 94 files and iterates again over the last 18 files!

• I can reproduce this issue calling the script through Apache as well a son the command line.
• I can reproduce it with PHP 7.4, 8.1 and 8.2 (other versions not tested)
• I can not reproduce it on my Ubuntu system
• I can not reproduce it on my Synology NAS

[kesselb]

Please report your finding(s) to https://bugs.php.net/how-to-report.php / https://github.com/php/php-src/issues/new/choose

[caco3]

Solved with #515