Stuck with "server replied: Internal Server Error"

Hi,

sorry for not being able to tell the exact history until my current issue occurred. I just suddenly saw that my desktop client was “gray” (NO SYNCHRONIZATION) and an error message

Error transferring https://192.168.1.79/status.php - server replied: Internal Server Error

occurred on the nextcloud client window.

Previous to that, I attempted to login from outside the LAN by using the “SimpleTask Nextcloud” APP together with my dynamic DNS name routed through into the LAN where my RaspberryPi server is located. The login failed more than once but might have caused some confusion to the Nextcloud service?

Is there a way to RECOVER from this error? Some way of clearing and re-setting the server?

… here is what the current MariaDB log status says:

pi@nextcloudpi:~ $ systemctl status mariadb
● mariadb.service - MariaDB database server
   Loaded: loaded (/lib/systemd/system/mariadb.service; enabled; vendor preset: enabled)
   Active: activating (start-pre) since Sun 2018-08-26 10:00:54 CEST; 18s ago
  Process: 12973 ExecStart=/usr/sbin/mysqld $MYSQLD_OPTS $_WSREP_NEW_CLUSTER $_WSREP_START_POSITION (code=exited, status=1/FAILURE)
  Process: 12993 ExecStartPre=/bin/sh -c [ ! -e /usr/bin/galera_recovery ] && VAR= ||   VAR=`/usr/bin/galera_recovery`; [ $? -eq 0 ]   && systemctl set-environment _WSREP_START_POSITION=$VAR || exit 1 (code=exited, status=0/SUCCESS)
  Process: 12989 ExecStartPre=/bin/sh -c systemctl unset-environment _WSREP_START_POSITION (code=exited, status=0/SUCCESS)
  Process: 12986 ExecStartPre=/usr/bin/install -m 755 -o mysql -g root -d /var/run/mysqld (code=exited, status=0/SUCCESS)
 Main PID: 12973 (code=exited, status=1/FAILURE); Control PID: 13091 (sleep)
   CGroup: /system.slice/mariadb.service
           └─control
             └─13091 /bin/sleep 20

Aug 26 10:00:54 nextcloudpi systemd[1]: Starting MariaDB database server...
pi@nextcloudpi:~ $

Maybe the “failure” blocks further activity?

… here the current mysql.log from /var/log/mysql/error.log:

2018-08-26 10:25:54 1988968448 [ERROR] mysqld: File '/media/USBdrive/ncdatabase/aria_log_control' not found (Errcode: 30 "Read-only file system")
2018-08-26 10:25:54 1988968448 [ERROR] mysqld: Got error 'Can't open file' when trying to use aria control file '/media/USBdrive/ncdatabase/aria_log_control'
2018-08-26 10:25:54 1988968448 [ERROR] Plugin 'Aria' init function returned error.
2018-08-26 10:25:54 1988968448 [ERROR] Plugin 'Aria' registration as a STORAGE ENGINE failed.
2018-08-26 10:25:54 1988968448 [Note] InnoDB: Using mutexes to ref count buffer pool pages
2018-08-26 10:25:54 1988968448 [Note] InnoDB: The InnoDB memory heap is disabled
2018-08-26 10:25:54 1988968448 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2018-08-26 10:25:54 1988968448 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2018-08-26 10:25:54 1988968448 [Note] InnoDB: Compressed tables use zlib 1.2.8
2018-08-26 10:25:54 1988968448 [Note] InnoDB: Using Linux native AIO
2018-08-26 10:25:54 1988968448 [Note] InnoDB: Using generic crc32 instructions
2018-08-26 10:25:54 1988968448 [Note] InnoDB: Initializing buffer pool, size = 128.0M
2018-08-26 10:25:54 1988968448 [Note] InnoDB: Completed initialization of buffer pool
2018-08-26 10:25:54 1988968448 [ERROR] InnoDB: ./ibdata1 can't be opened in read-write mode
2018-08-26 10:25:54 1988968448 [ERROR] InnoDB: The system tablespace must be writable!
2018-08-26 10:25:54 1988968448 [ERROR] Plugin 'InnoDB' init function returned error.
2018-08-26 10:25:54 1988968448 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
2018-08-26 10:25:54 1988968448 [Note] Plugin 'FEEDBACK' is disabled.
2018-08-26 10:25:54 1988968448 [ERROR] Unknown/unsupported storage engine: InnoDB
2018-08-26 10:25:54 1988968448 [ERROR] Aborting

… here some further system information:

Nextcloud version:
13.0.4

Operating system and version:
NextCloudPi v0.58.1
Raspbian GNU/Linux 9

My issue:
NO synchronization possible

Steps to replicate it:
no reproduction necessary. State is permanent. Even new power-up of Server (RaspberryPi) shows no difference.

The latest outputs, from 18.08.2018, of the nextcloud.log show:

{"reqId":"W3gu8X8AAQEAAEjewmMAABUN","level":4,"time":"2018-08-18T14:36:34+00:00","remoteAddr":"192.168.1.34","user"
:"ncp","app":"webdav","method":"GET","url":"\/remote.php\/dav\/addressbooks\/system\/system\/system\/Database:Nnamd
i.vcf?photo&size=32","message":"Exception: {\"Exception\":\"Doctrine\\\\DBAL\\\\Exception\\\\UniqueConstraintViolat
ionException\",\"Message\":\"An exception occurred while executing 'INSERT INTO `oc_filecache` (`mimepart`,`mimetype`,`mtime`,`size`,`etag`,`storage_mtime`,`permissions`,`parent`,`checksum`,`path_hash`,`path`,`name`,`storage`) SELECT ?,?,?,?,?,?,?,?,?,?,?,?,? FROM `oc_filecache` WHERE `storage` = ? AND `path_hash` = ? HAVING COUNT(*) = 0' with params [\\\"1\\\", \\\"2\\\", 1534602993, -1, \\\"5b782ef198152\\\", 1534602993, 31, 25, \\\"\\\", \\\"f7f2d9f0427c14488b2f9046d979c0e0\\\", \\\"appdata_oc1lgek82p77\\\\\\\/dav-photocache\\\", \\\"dav-photocache\\\", 3, 3, \\\"f7f2d9f0427c14488b2f9046d979c0e0\\\"]:\\n\\nSQLSTATE[23000]: Integrity constraint violation: 1062 Duplicate entry '3-f7f2d9f0427c14488b2f9046d979c0e0' for key 'fs_storage_path_hash'\",\"Code\":0,\"Trace\":\"#0 \\\/var\\\/www\\\/nextcloud\\\/3rdparty\\\/doctrine\\\/dbal\\\/lib\\\/Doctrine\\\/DBAL\\\/DBALException.php(128): Doctrine\\\\DBAL\\\\Driver\\\\AbstractMySQLDriver->convertException('An exception oc...', Object(Doctrine\\\\DBAL\\\\Driver\\\\PDOException))\\n#1 \\\/var\\\/www\\\/nextcloud\\\/3rdparty\\\/doctrine\\\/dbal\\\/lib\\\/Doctrine\\\/DBAL\\\/Connection.php(1015): Doctrine\\\\DBAL\\\\DBALException::driverExceptionDuringQuery(Object(Doctrine\\\\DBAL\\\\Driver\\\\PDOMySql\\\\Driver), Object(Doctrine\\\\DBAL\\\\Driver\\\\PDOException), 'INSERT INTO `oc...', Array)\\n#2 \\\/var\\\/www\\\/nextcloud\\\/lib\\\/private\\\/DB\\\/Connection.php(216): Doctrine\\\\DBAL\\\\Connection->executeUpdate('INSERT INTO `oc...', Array, Array)\\n#3 \\\/var\\\/www\\\/nextcloud\\\/lib\\\/private\\\/DB\\\/Adapter.php(114): OC\\\\DB\\\\Connection->executeUpdate('INSERT INTO `oc...', Array)\\n#4 \\\/var\\\/www\\\/nextcloud\\\/lib\\\/private\\\/DB\\\/Connection.php(254): OC\\\\DB\\\\Adapter->insertIfNotExist('*PREFIX*filecac...', Array, Array)\\n#5 \\\/var\\\/www\\\/nextcloud\\\/lib\\\/private\\\/Files\\\/Cache\\\/Cache.php(273): OC\\\\DB\\\\Connection->insertIfNotExist('*PREFIX*filecac...', Array, Array)\\n#6 \\\/var\\\/www\\\/nextcloud\\\/lib\\\/private\\\/Files\\\/Cache\\\/Cache.php(230): OC\\\\Files\\\\Cache\\\\Cache->insert('appdata_oc1lgek...', Array)\\n#7 \\\/var\\\/www\\\/nextcloud\\\/lib\\\/private\\\/Files\\\/Cache\\\/Scanner.php(292): OC\\\\Files\\\\Cache\\\\Cache->put('appdata_oc1lgek...', Array)\\n#8 \\\/var\\\/www\\\/nextcloud\\\/lib\\\/private\\\/Files\\\/Cache\\\/Scanner.php(221): OC\\\\Files\\\\Cache\\\\Scanner->addToCache('appdata_oc1lgek...', Array, -1)\\n#9 \\\/var\\\/www\\\/nextcloud\\\/lib\\\/private\\\/Files\\\/Cache\\\/Scanner.php(336): OC\\\\Files\\\\Cache\\\\Scanner->scanFile('appdata_oc1lgek...', 3, 25, false, false)\\n#10 \\\/var\\\/www\\\/nextcloud\\\/lib\\\/private\\\/Files\\\/Cache\\\/Updater.php(124): OC\\\\Files\\\\Cache\\\\Scanner->scan('appdata_oc1lgek...', false, 3, false)\\n#11 \\\/var\\\/www\\\/nextcloud\\\/lib\\\/private\\\/Files\\\/View.php(319): OC\\\\Files\\\\Cache\\\\Updater->update('appdata_oc1lgek...', 1534602993)\\n#12 \\\/var\\\/www\\\/nextcloud\\\/lib\\\/private\\\/Files\\\/View.php(1163): OC\\\\Files\\\\View->writeUpdate(Object(OCA\\\\Files_Trashbin\\\\Storage), 'appdata_oc1lgek...')\\n#13 \\\/var\\\/www\\\/nextcloud\\\/lib\\\/private\\\/Files\\\/View.php(267): OC\\\\Files\\\\View->basicOperation('mkdir', '\\\/appdata_oc1lge...', Array)\\n#14 \\\/var\\\/www\\\/nextcloud\\\/lib\\\/private\\\/Files\\\/Node\\\/Folder.php(160): OC\\\\Files\\\\View->mkdir('\\\/appdata_oc1lge...')\\n#15 \\\/var\\\/www\\\/nextcloud\\\/lib\\\/private\\\/Files\\\/AppData\\\/AppData.php(92): OC\\\\Files\\\\Node\\\\Folder->newFolder('dav-photocache')\\n#16 \\\/var\\\/www\\\/nextcloud\\\/lib\\\/private\\\/Files\\\/AppData\\\/AppData.php(105): OC\\\\Files\\\\AppData\\\\AppData->getAppDataFolder()\\n#17 \\\/var\\\/www\\\/nextcloud\\\/apps\\\/dav\\\/lib\\\/CardDAV\\\/PhotoCache.php(164): OC\\\\Files\\\\AppData\\\\AppData->getFolder('1bc8bce7ffaef70...')\\n#18 \\\/var\\\/www\\\/nextcloud\\\/apps\\\/dav\\\/lib\\\/CardDAV\\\/PhotoCache.php(59): OCA\\\\DAV\\\\CardDAV\\\\PhotoCache->getFolder('2', 'Database:MyName...')\\n#19 \\\/var\\\/www\\\/nextcloud\\\/apps\\\/dav\\\/lib\\\/CardDAV\\\/ImageExportPlugin.php(105): OCA\\\\DAV\\\\CardDAV\\\\PhotoCache->get('2', 'Database:MyName...', 32, Object(Sabre\\\\CardDAV\\\\Card))\\n#20 [internal function]: OCA\\\\DAV\\\\CardDAV\\\\ImageExportPlugin->httpGet(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n#21 \\\/var\\\/www\\\/nextcloud\\\/3rdparty\\\/sabre\\\/event\\\/lib\\\/EventEmitterTrait.php(105): call_user_func_array(Array, Array)\\n#22 \\\/var\\\/www\\\/nextcloud\\\/3rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(479): Sabre\\\\Event\\\\EventEmitter->emit('method:GET', Array)\\n#23 \\\/var\\\/www\\\/nextcloud\\\/3rdparty\\\/sabre\\\/dav\\\/lib\\\/DAV\\\/Server.php(254): Sabre\\\\DAV\\\\Server->invokeMethod(Object(Sabre\\\\HTTP\\\\Request), Object(Sabre\\\\HTTP\\\\Response))\\n#24 \\\/var\\\/www\\\/nextcloud\\\/apps\\\/dav\\\/lib\\\/Server.php(287): Sabre\\\\DAV\\\\Server->exec()\\n#25 \\\/var\\\/www\\\/nextcloud\\\/apps\\\/dav\\\/appinfo\\\/v2\\\/remote.php(35): OCA\\\\DAV\\\\Server->exec()\\n#26 \\\/var\\\/www\\\/nextcloud\\\/remote.php(164): require_once('\\\/var\\\/www\\\/nextcl...')\\n#27 {main}\",\"File\":\"\\\/var\\\/www\\\/nextcloud\\\/3rdparty\\\/doctrine\\\/dbal\\\/lib\\\/Doctrine\\\/DBAL\\\/Driver\\\/AbstractMySQLDriver.php\",\"Line\":66}","userAgent":"Mozilla\/5.0 (Windows NT 6.1; Win64; x64; rv:61.0) Gecko\/20100101 Firefox\/61.0","version":"13.0.4.0"}
{"reqId":"W3hAHX8AAQEAAEjew3IAABUF","level":2,"time":"2018-08-18T15:49:49+00:00","remoteAddr":"137.226.113.20","user":"--","app":"core","method":"GET","url":"\/","message":"Trusted domain error. \"137.226.113.20\" tried to access using \"78.52.212.89\" as host.","userAgent":"Mozilla\/5.0 (X11; Ubuntu; Linux x86_64; rv:50.0) Gecko\/20100101 Firefox\/50.0","version":"13.0.4.0"}
{"reqId":"W3hAHn8AAQEAAEjew3gAABUc","level":2,"time":"2018-08-18T15:49:50+00:00","remoteAddr":"137.226.113.20","user":"--","app":"core","method":"GET","url":"\/index.php\/js\/core\/merged-template-prepend.js?v=da743983-0","message":"Trusted domain error. \"137.226.113.20\" tried to access using \"78.52.212.89\" as host.","userAgent":"Mozilla\/5.0 (X11; Ubuntu; Linux x86_64; rv:50.0) Gecko\/20100101 Firefox\/50.0","version":"13.0.4.0"}
{"reqId":"W3hX-X8AAQEAAEjew38AAAAM","level":2,"time":"2018-08-18T17:31:41+00:00","remoteAddr":"84.95.214.222","user":"--","app":"core","method":"GET","url":"\/cgi-bin\/webcm?getpage=..\/html\/menus\/menu2.html&var:lang=%26%20allcfgconv%20-C%20voip%20-c%20-o%20-%20..\/..\/..\/..\/..\/var\/tmp\/voip.cfg%20%26","message":"Trusted domain error. \"84.95.214.222\" tried to access using \"78.52.212.89\" as host.","userAgent":"Mozilla\/5.0 (Windows NT 6.2; WOW64; rv:37.0) Gecko\/20100101 Firefox\/37.0","version":"13.0.4.0"}
{"reqId":"W3hlT38AAQEAAEjew4AAAAAY","level":2,"time":"2018-08-18T18:28:31+00:00","remoteAddr":"54.89.132.215","user":"--","app":"core","method":"GET","url":"\/","message":"Trusted domain error. \"54.89.132.215\" tried to access using \"78.52.212.89\" as host.","userAgent":"Mozilla\/5.0 (Windows NT 6.2;en-US) AppleWebKit\/537.32.36 (KHTML, live Gecko) Chrome\/60.0.3075.57 Safari\/537.32","version":"13.0.4.0"}
{"reqId":"W3ieV38AAQEAAEjew4YAAAAP","level":2,"time":"2018-08-18T22:31:51+00:00","remoteAddr":"107.170.205.189","user":"--","app":"core","method":"GET","url":"\/","message":"Trusted domain error. \"107.170.205.189\" tried to access using \"78.52.212.89\" as host.","userAgent":"Mozilla\/5.0 zgrab\/0.x","version":"13.0.4.0"}

The output of your config.php file in /path/to/nextcloud (make sure you remove any identifiable information!):

<?php
$CONFIG = array (
  'passwordsalt' => 'xxx',
  'secret' => 'xxx',
  'trusted_domains' =>
  array (
    0 => 'localhost',
    5 => 'nextcloudpi.local',
    1 => '192.168.1.79',
    3 => 'xxx',
  ),
  'datadirectory' => '/media/USBdrive/ncdata',
  'overwrite.cli.url' => 'xxx',
  'dbtype' => 'mysql',
  'version' => '13.0.4.0',
  'dbname' => 'nextcloud',
  'dbhost' => 'localhost',
  'dbport' => '',
  'dbtableprefix' => 'oc_',
  'mysql.utf8mb4' => true,
  'dbuser' => 'ncadmin',
  'dbpassword' => 'xxx',
  'installed' => true,
  'instanceid' => 'oc1lgek82p77',
  'memcache.local' => '\\OC\\Memcache\\Redis',
  'memcache.locking' => '\\OC\\Memcache\\Redis',
  'redis' =>
  array (
    'host' => '/var/run/redis/redis.sock',
    'port' => 0,
    'timeout' => 0.0,
    'password' => 'xxx',
  ),
  'mail_smtpmode' => 'php',
  'mail_smtpauthtype' => 'LOGIN',
  'mail_from_address' => 'admin',
  'mail_domain' => 'ownyourbits.com',
  'overwriteprotocol' => 'https',
  'maintenance' => false,
  'logfile' => '/media/USBdrive/ncdata/nextcloud.log',
);

The output of my Apache/nginx/system log in /var/log/apache2/error.log:

[Thu Aug 23 06:25:03.041968 2018] [ssl:warn] [pid 25256:tid 1992302592] AH01909: localhost:4443:0 server certificate does NOT include an ID which matches the server name
[Thu Aug 23 06:25:03.042576 2018] [ssl:error] [pid 25256:tid 1992302592] AH02217: ssl_stapling_init_cert: can't retrieve issuer certificate! [subject: CN=desktop / issuer: CN=desktop / serial: E22858A05CCC728F / notbefore: Jun 27 16:34:34 2018 GMT / notafter: Jun 24 16:34:34 2028 GMT]
[Thu Aug 23 06:25:03.042621 2018] [ssl:error] [pid 25256:tid 1992302592] AH02604: Unable to configure certificate localhost:4443:0 for stapling
[Thu Aug 23 06:25:04.001328 2018] [mpm_event:notice] [pid 25256:tid 1992302592] AH00489: Apache/2.4.25 (Raspbian) OpenSSL/1.0.2l configured -- resuming normal operations
[Thu Aug 23 06:25:04.001461 2018] [core:notice] [pid 25256:tid 1992302592] AH00094: Command line: '/usr/sbin/apache2'
[Thu Aug 23 07:23:16.993336 2018] [proxy_fcgi:error] [pid 23915:tid 1733149744] [client 192.168.1.34:49321] AH01071: Got error 'PHP message: PHP Warning:  fclose(): supplied resource is not a valid stream resource in /var/www/ncp-web/L10N.php on line 166\n'
[Thu Aug 23 07:23:23.549331 2018] [proxy_fcgi:error] [pid 23915:tid 1817052208] [client 192.168.1.34:49321] AH01071: Got error 'PHP message: PHP Warning:  touch(): Utime failed: Permission denied in /var/www/ncp-web/ncp-output.php on line 81\n'
[Thu Aug 23 07:23:34.053638 2018] [proxy_fcgi:error] [pid 23915:tid 1733149744] [client 192.168.1.34:49321] AH01071: Got error 'PHP message: PHP Warning:  fclose(): supplied resource is not a valid stream resource in /var/www/ncp-web/L10N.php on line 166\n'
[Thu Aug 23 11:56:55.766969 2018] [proxy_fcgi:error] [pid 23916:tid 1749943344] [client 192.168.1.34:50574] AH01071: Got error 'PHP message: PHP Warning:  fclose(): supplied resource is not a valid stream resource in /var/www/ncp-web/L10N.php on line 166\n'
[Thu Aug 23 11:57:02.141636 2018] [proxy_fcgi:error] [pid 23916:tid 1749943344] [client 192.168.1.34:50574] AH01071: Got error 'PHP message: PHP Warning:  touch(): Utime failed: Permission denied in /var/www/ncp-web/ncp-output.php on line 81\n'
[Thu Aug 23 11:57:03.143472 2018] [proxy_fcgi:error] [pid 23916:tid 1984824368] [client 192.168.1.34:50574] AH01071: Got error 'PHP message: PHP Warning:  fclose(): supplied resource is not a valid stream resource in /var/www/ncp-web/L10N.php on line 166\n'
[Thu Aug 23 11:57:07.243605 2018] [proxy_fcgi:error] [pid 23916:tid 1984824368] [client 192.168.1.34:50574] AH01071: Got error 'PHP message: PHP Warning:  fclose(): supplied resource is not a valid stream resource in /var/www/ncp-web/L10N.php on line 166\n'
[Thu Aug 23 12:06:15.989451 2018] [mpm_event:notice] [pid 25256:tid 1992302592] AH00491: caught SIGTERM, shutting down
[Thu Aug 23 12:06:16.256116 2018] [ssl:warn] [pid 1591:tid 1992679424] AH01909: localhost:4443:0 server certificate does NOT include an ID which matches the server name
[Thu Aug 23 12:06:16.256684 2018] [ssl:error] [pid 1591:tid 1992679424] AH02217: ssl_stapling_init_cert: can't retrieve issuer certificate! [subject: CN=desktop / issuer: CN=desktop / serial: E22858A05CCC728F / notbefore: Jun 27 16:34:34 2018 GMT / notafter: Jun 24 16:34:34 2028 GMT]
[Thu Aug 23 12:06:16.256729 2018] [ssl:error] [pid 1591:tid 1992679424] AH02604: Unable to configure certificate localhost:4443:0 for stapling
[Thu Aug 23 12:06:17.090284 2018] [ssl:warn] [pid 1592:tid 1992679424] AH01909: localhost:4443:0 server certificate does NOT include an ID which matches the server name
[Thu Aug 23 12:06:17.090896 2018] [ssl:error] [pid 1592:tid 1992679424] AH02217: ssl_stapling_init_cert: can't retrieve issuer certificate! [subject: CN=desktop / issuer: CN=desktop / serial: E22858A05CCC728F / notbefore: Jun 27 16:34:34 2018 GMT / notafter: Jun 24 16:34:34 2028 GMT]
[Thu Aug 23 12:06:17.090943 2018] [ssl:error] [pid 1592:tid 1992679424] AH02604: Unable to configure certificate localhost:4443:0 for stapling
[Thu Aug 23 12:06:18.005499 2018] [mpm_event:notice] [pid 1592:tid 1992679424] AH00489: Apache/2.4.25 (Raspbian) OpenSSL/1.0.2l configured -- resuming normal operations
[Thu Aug 23 12:06:18.005850 2018] [core:notice] [pid 1592:tid 1992679424] AH00094: Command line: '/usr/sbin/apache2'
[Thu Aug 23 13:46:50.625567 2018] [proxy_fcgi:error] [pid 1597:tid 1683153968] [client 192.168.1.34:49417] AH01071: Got error 'PHP message: PHP Warning:  fclose(): supplied resource is not a valid stream resource in /var/www/ncp-web/L10N.php on line 166\n'
[Thu Aug 23 13:46:51.691770 2018] [proxy_fcgi:error] [pid 1597:tid 1683153968] [client 192.168.1.34:49417] AH01071: Got error 'PHP message: PHP Warning:  fclose(): supplied resource is not a valid stream resource in /var/www/ncp-web/L10N.php on line 166\n'
[Thu Aug 23 13:46:55.768037 2018] [proxy_fcgi:error] [pid 1597:tid 1691550768] [client 192.168.1.34:49417] AH01071: Got error 'PHP message: PHP Warning:  touch(): Utime failed: Permission denied in /var/www/ncp-web/ncp-output.php on line 81\n'
[Thu Aug 23 13:47:42.699282 2018] [proxy_fcgi:error] [pid 1596:tid 1691550768] [client 192.168.1.34:49463] AH01071: Got error 'PHP message: PHP Warning:  fclose(): supplied resource is not a valid stream resource in /var/www/ncp-web/L10N.php on line 166\n'
[Thu Aug 23 13:47:48.829705 2018] [proxy_fcgi:error] [pid 1596:tid 1733534768] [client 192.168.1.34:49463] AH01071: Got error 'PHP message: PHP Warning:  touch(): Utime failed: Permission denied in /var/www/ncp-web/ncp-output.php on line 81\n'
[Thu Aug 23 13:47:49.918676 2018] [proxy_fcgi:error] [pid 1596:tid 1716741168] [client 192.168.1.34:49463] AH01071: Got error 'PHP message: PHP Warning:  fclose(): supplied resource is not a valid stream resource in /var/www/ncp-web/L10N.php on line 166\n'
[Thu Aug 23 13:47:53.012036 2018] [proxy_fcgi:error] [pid 1596:tid 1716741168] [client 192.168.1.34:49463] AH01071: Got error 'PHP message: PHP Warning:  fclose(): supplied resource is not a valid stream resource in /var/www/ncp-web/L10N.php on line 166\n'
[Thu Aug 23 14:40:22.825532 2018] [proxy_fcgi:error] [pid 1596:tid 1716741168] [client 192.168.1.34:49463] AH01071: Got error 'PHP message: PHP Warning:  fclose(): supplied resource is not a valid stream resource in /var/www/ncp-web/L10N.php on line 166\n'
[Thu Aug 23 14:40:37.702053 2018] [proxy_fcgi:error] [pid 1596:tid 1716741168] [client 192.168.1.34:49463] AH01071: Got error 'PHP message: PHP Warning:  fclose(): supplied resource is not a valid stream resource in /var/www/ncp-web/L10N.php on line 166\n'
[Thu Aug 23 14:40:46.036922 2018] [proxy_fcgi:error] [pid 1596:tid 1716741168] [client 192.168.1.34:49463] AH01071: Got error 'PHP message: PHP Warning:  fclose(): supplied resource is not a valid stream resource in /var/www/ncp-web/L10N.php on line 166\n'
[Thu Aug 23 14:47:17.425834 2018] [proxy_fcgi:error] [pid 1596:tid 1716741168] [client 192.168.1.34:49463] AH01071: Got error 'PHP message: PHP Warning:  fclose(): supplied resource is not a valid stream resource in /var/www/ncp-web/L10N.php on line 166\n'
[Thu Aug 23 14:47:23.600290 2018] [proxy_fcgi:error] [pid 1596:tid 1716741168] [client 192.168.1.34:49463] AH01071: Got error 'PHP message: PHP Warning:  touch(): Utime failed: Permission denied in /var/www/ncp-web/ncp-output.php on line 81\n'
[Thu Aug 23 14:47:24.724692 2018] [proxy_fcgi:error] [pid 1596:tid 1733534768] [client 192.168.1.34:49463] AH01071: Got error 'PHP message: PHP Warning:  fclose(): supplied resource is not a valid stream resource in /var/www/ncp-web/L10N.php on line 166\n'
[Thu Aug 23 14:47:27.796206 2018] [proxy_fcgi:error] [pid 1596:tid 1733534768] [client 192.168.1.34:49463] AH01071: Got error 'PHP message: PHP Warning:  fclose(): supplied resource is not a valid stream resource in /var/www/ncp-web/L10N.php on line 166\n'

The output of my Apache/nginx/system log in /var/log/apache2/nc-error.log:

[Fri Aug 24 12:56:10.396012 2018] [proxy_fcgi:error] [pid 10470:tid 1505743920] [client 192.168.1.90:57853] AH01071: Got error 'PHP message: PHP Fatal error:  Uncaught Doctrine\\DBAL\\DBALException: Failed to connect to the database: An exception occured in driver: SQLSTATE[HY000] [2002] Connection refused in /var/www/nextcloud/lib/private/DB/Connection.php:64\nStack trace:\n#0 /var/www/nextcloud/3rdparty/doctrine/dbal/lib/Doctrine/DBAL/Connection.php(429): OC\\DB\\Connection->connect()\n#1 /var/www/nextcloud/3rdparty/doctrine/dbal/lib/Doctrine/DBAL/Connection.php(389): Doctrine\\DBAL\\Connection->getDatabasePlatformVersion()\n#2 /var/www/nextcloud/3rdparty/doctrine/dbal/lib/Doctrine/DBAL/Connection.php(328): Doctrine\\DBAL\\Connection->detectDatabasePlatform()\n#3 /var/www/nextcloud/3rdparty/doctrine/dbal/lib/Doctrine/DBAL/Connection.php(623): Doctrine\\DBAL\\Connection->getDatabasePlatform()\n#4 /var/www/nextcloud/lib/private/DB/Connection.php(151): Doctrine\\DBAL\\Connection->setTransactionIsolation(2)\n#5 /var/www/nextcloud/3rdparty/doctrine/dbal/lib/Doctrine/DBAL/DriverManager.php(172): OC\\DB\\Connection->__construct(Array, Object(Doctrine\\DBAL\\...\nPHP message: PHP Fatal error:  Uncaught Doctrine\\DBAL\\DBALException: Failed to connect to the database: An exception occured in driver: SQLSTATE[HY000] [2002] Connection refused in /var/www/nextcloud/lib/private/DB/Connection.php:64\nStack trace:\n#0 /var/www/nextcloud/3rdparty/doctrine/dbal/lib/Doctrine/DBAL/Connection.php(429): OC\\DB\\Connection->connect()\n#1 /var/www/nextcloud/3rdparty/doctrine/dbal/lib/Doctrine/DBAL/Connection.php(389): Doctrine\\DBAL\\Connection->getDatabasePlatformVersion()\n#2 /var/www/nextcloud/3rdparty/doctrine/dbal/lib/Doctrine/DBAL/Connection.php(328): Doctrine\\DBAL\\Connection->detectDatabasePlatform()\n#3 /var/www/nextcloud/3rdparty/doctrine/dbal/lib/Doctrine/DBAL/Connection.php(623): Doctrine\\DBAL\\Connection->getDatabasePlatform()\n#4 /var/www/nextcloud/lib/private/DB/Connection.php(151): Doctrine\\DBAL\\Connection->setTransactionIsolation(2)\n#5 /var/www/nextcloud/3rdparty/doctrine/dbal/lib/Doctrine/DBAL/DriverManager.php(172): OC\\DB\\Connection->__construct(Array, Object(Doctrine\\DBAL\\...\n'

What is “Doctrine” doing?

Hi,

actually, your database can’t open it’s database file for read-write operations, as stated here:

2018-08-26 10:25:54 1988968448 [ERROR] mysqld: File '/media/USBdrive/ncdatabase/aria_log_control' not found (Errcode: 30 "Read-only file system")

Check your USB drive for errors and try again.

Thanks for your answer.

Here’s the ls of the mounted USB drive. Seems ok to me. Maybe the owners got corrupted? What would be the standard ownership settings here?

pi@nextcloudpi:~ $ ls -al /media/USBdrive/ncdatabase
insgesamt 176188
drwxr-xr-x 1 mysql mysql      266 Aug 19 13:27 .
drwxr-xr-x 1 root  root        32 Aug  4 19:29 ..
-rw-rw---- 1 mysql mysql    16384 Aug  4 19:29 aria_log.00000001
-rw-rw---- 1 mysql mysql       52 Aug  4 19:29 aria_log_control
-rw-r--r-- 1 root  root         0 Jun 27 18:32 debian-10.1.flag
-rw-rw---- 1 mysql mysql 79691776 Aug 23 11:39 ibdata1
-rw-rw---- 1 mysql mysql 50331648 Aug 23 11:39 ib_logfile0
-rw-rw---- 1 mysql mysql 50331648 Aug 17 21:51 ib_logfile1
-rw-rw---- 1 mysql mysql        0 Jun 27 18:34 multi-master.info
drwx------ 1 mysql root      2600 Jun 27 18:33 mysql
drwx------ 1 mysql mysql     4568 Jun 27 19:47 nextcloud
drwx------ 1 mysql mysql       12 Jun 27 18:33 performance_schema
-rw-rw---- 1 mysql mysql    24576 Aug 19 13:27 tc.log

Well… that isn’t what the error told us. It said, that the file aria_log_control couldn’t be opened for writing. Best would be to stop mariadb unmount the USB drive and perform a fsck on it. Then mount it again and start mariadb and see, if it can access the log in read/write mode.

I stopped MariaDB…

pi@nextcloudpi:~ $ sudo systemctl stop mariadb

seemed to work. Then unmount the USB device, remount and after that tried to restarting MariaDB failed with the following output:

pi@nextcloudpi:~ $ sudo systemctl restart mariadb
Job for mariadb.service failed because the control process exited with error code.
See "systemctl status mariadb.service" and "journalctl -xe" for details.

… then I tried the suggestion:

pi@nextcloudpi:~ $ systemctl status mariadb.service
● mariadb.service - MariaDB database server
   Loaded: loaded (/lib/systemd/system/mariadb.service; enabled; vendor preset: enabled)
   Active: activating (start-pre) since Sun 2018-08-26 15:07:22 CEST; 1s ago
  Process: 31053 ExecStart=/usr/sbin/mysqld $MYSQLD_OPTS $_WSREP_NEW_CLUSTER $_WSREP_START_POSITION (code=exited, s
  Process: 31051 ExecStartPre=/bin/sleep 20 (code=exited, status=0/SUCCESS)
  Process: 31070 ExecStartPre=/bin/sh -c systemctl unset-environment _WSREP_START_POSITION (code=exited, status=0/S
  Process: 31067 ExecStartPre=/usr/bin/install -m 755 -o mysql -g root -d /var/run/mysqld (code=exited, status=0/SU
 Main PID: 31053 (code=exited, status=1/FAILURE); Control PID: 31074 (sh)
   CGroup: /system.slice/mariadb.service
           └─control
             ├─31074 /bin/sh -c [ ! -e /usr/bin/galera_recovery ] && VAR= ||   VAR=`/usr/bin/galera_recovery`; [ $?
             ├─31075 /bin/sh /usr/bin/galera_recovery
             ├─31143 /bin/sh /usr/bin/galera_recovery
             └─31145 sed -e s;--[^=]*=;;

Aug 26 15:07:22 nextcloudpi systemd[1]: Starting MariaDB database server...

after another failed restart, I get this when requesting the status:

pi@nextcloudpi:~ $ systemctl status mariadb.service
● mariadb.service - MariaDB database server
   Loaded: loaded (/lib/systemd/system/mariadb.service; enabled; vendor preset: enabled)
   Active: activating (start-pre) since Sun 2018-08-26 15:15:11 CEST; 21s ago
  Process: 898 ExecStart=/usr/sbin/mysqld $MYSQLD_OPTS $_WSREP_NEW_CLUSTER $_WSREP_START_POSITION (code=exited, status=1/FAILURE)
  Process: 923 ExecStartPre=/bin/sh -c [ ! -e /usr/bin/galera_recovery ] && VAR= ||   VAR=`/usr/bin/galera_recovery`; [ $? -eq 0 ]   && systemctl set-environment _WSREP_START_POSITION=$VAR || exit 1 (code=exited, status=0/SUCCESS)
  Process: 919 ExecStartPre=/bin/sh -c systemctl unset-environment _WSREP_START_POSITION (code=exited, status=0/SUCCESS)
  Process: 916 ExecStartPre=/usr/bin/install -m 755 -o mysql -g root -d /var/run/mysqld (code=exited, status=0/SUCCESS)
 Main PID: 898 (code=exited, status=1/FAILURE); Control PID: 1023 (sleep)
   CGroup: /system.slice/mariadb.service
           └─control
             └─1023 /bin/sleep 20

Aug 26 15:15:11 nextcloudpi systemd[1]: Starting MariaDB database server...

As I am no expert in tracking DB issues, I’m still stuck, here. Any clue how to proceed?

Maybe a look at the mysql error log in /var/log/mysql/error.log will shed some light on this.

Here’s what the MySQL error log says from /var/log/mysql/error.log. It repeats itself every ~30 seconds:

2018-08-26 17:16:51 1989054464 [ERROR] mysqld: File '/media/USBdrive/ncdatabase/aria_log_control' not found (Errcode: 30 "Read-only file system")
2018-08-26 17:16:51 1989054464 [ERROR] mysqld: Got error 'Can't open file' when trying to use aria control file '/media/USBdrive/ncdatabase/aria_log_control'
2018-08-26 17:16:51 1989054464 [ERROR] Plugin 'Aria' init function returned error.
2018-08-26 17:16:51 1989054464 [ERROR] Plugin 'Aria' registration as a STORAGE ENGINE failed.
2018-08-26 17:16:51 1989054464 [Note] InnoDB: Using mutexes to ref count buffer pool pages
2018-08-26 17:16:51 1989054464 [Note] InnoDB: The InnoDB memory heap is disabled
2018-08-26 17:16:51 1989054464 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2018-08-26 17:16:51 1989054464 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2018-08-26 17:16:51 1989054464 [Note] InnoDB: Compressed tables use zlib 1.2.8
2018-08-26 17:16:51 1989054464 [Note] InnoDB: Using Linux native AIO
2018-08-26 17:16:51 1989054464 [Note] InnoDB: Using generic crc32 instructions
2018-08-26 17:16:51 1989054464 [Note] InnoDB: Initializing buffer pool, size = 128.0M
2018-08-26 17:16:51 1989054464 [Note] InnoDB: Completed initialization of buffer pool
2018-08-26 17:16:51 1989054464 [ERROR] InnoDB: ./ibdata1 can't be opened in read-write mode
2018-08-26 17:16:51 1989054464 [ERROR] InnoDB: The system tablespace must be writable!
2018-08-26 17:16:51 1989054464 [ERROR] Plugin 'InnoDB' init function returned error.
2018-08-26 17:16:51 1989054464 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
2018-08-26 17:16:51 1989054464 [Note] Plugin 'FEEDBACK' is disabled.
2018-08-26 17:16:51 1989054464 [ERROR] Unknown/unsupported storage engine: InnoDB
2018-08-26 17:16:51 1989054464 [ERROR] Aborting

And indeed, I cannot write anything to the location

/media/USBdrive/ncdatabase/

even as su.

Well, then try to fix that first… without write-access, mariadb won’t work of course. Your USB drive might also got corrupted - better to plug it into a PC and get all the data off it, you can.

You will need to know, the device’s location, so issue a mount on the terminal and look where that USBdrive is connected from. You will see the device and the mount point, which is /media/USBdrive (presumeably, since you seem to host either the mysql database and your NC data folder on it).

If you’ve got the device where the /media/USB is connected to, unmount the volume and perform a fsck on the device. If unsure, post the output of mount and I will tell you what to do.

What kind of USB drive is that?

Hi @budy, thanks for your support. I re-mounted the USB drive again and then the system at least returned to kind-of-normal. Unfortunately, a lot of other “problems” became visible after returning to operational mode. So, different client computers encountered different files which were downloaded from the server with 0 Bytes length although the server still held the correct files with a matching file size…

Strange, but after a couple of hours, I managed to get the whole system to normal operation again:

  • duplicate the files under a different name (files which were messed up on the clients)
  • remove the messed up files from the server AND the clients (they did not necessarily disappear)
  • remove ALL files from the server’s trash bin (no possibility to return to former messed up files)
  • disconnect and re-connect all clients from / to the server
  • rename the “new” duplicates on the server to the old names

The expected files were updated on the clients and until then, the whole system is stable again :slight_smile: . But, anyway, I am still a bit nervous not to cause the system to crash like this again, as I still don’t know which combination of conditions might have caused the odd behaviour in the first place.

Thanks.

What kind of USB drive is that? Is it a “real” drive or a flash drive? If it’s a thumb drive, than you might be wearing out the flash storage through mariadb, which might cause defective sectors on the flash drive. Or maybe the USB drive had a temporary connection problem and thus the file system on it turned read-only.

I have seen a dozen or so, microSD cards being broken by “regular” use of a RPi, when the owner thought, that the usage wouldn’t be that heavy.

When I was using a RPi3 as my NC host, I booted and operated it from a little SSD SATA drive, which I hooked up via USB. Since these SATA SSDs are way more resillient against these issues of their medium wearing out, I never encountered any issue with that.
If you already operate a “real” disk via USB make sure, that there’s enough power provided to the USB-Bridge/Drive.

Cheers,
budy

Currently, I use an “ordinary” 32GB-USB-Memory-Stick plugged into one of the PI’s USB ports. I didn’t know that MariaDB does a lot of overhead reading/writing. I came from OwnCloud which (at that time) used Sqlite3. It was told that an ordinary USB-Memory-Stick was perfect for small file stores.

So, I will get myself a USB-pluggable SSD drive and hope to be able to migrate everything onto the new SSD drive without loss and without errors.

  • is there any SSD you could recommend?
  • is there any information about migrating the NC’s server files onto an other device?

Thanks for your information.

Well, I’d say, that almost any SATA SSD will outperform any ordinary regular USB Memory-Stick in regards of durability, I don’t can’t actually recommend any one in particular. You could probably grab the smallest of them and be good.

Regarding the data transfer, this should be straight forward. Just have both drives connected to your RPi and shutdown all the services, which are writing to the USB memory stick. Then simply copy all the contents to the new SSD and unmount both volumes afterwards. Then modify /etc/fstab such as that the new SSD drive will mount to the same mount point as the memory stick did. That should do it.

If in doubt, feel free to ask.

Cheers,
budy