Nextcloud upgrade failed

:uk:/:us: Message template (english)

Hi,
I tried to update my yunohost apps but nextcloud fails again, not sure why :-/ any help is welcome. hopefully i will be able to debug this in the future, but for now, i am not sure where to start

My YunoHost server

Hardware: macbook air
YunoHost version: 4.3.6.2
**I have access to my server :Through SSH | through the webadmin | direct access via keyboard / screen
Are you in a special context or did you perform some particular tweaking on your YunoHost instance ? : no / some docker containers installed but should not interfere

Description of my issue

upgrade of nextcloud fails either through cammand line or webadmin
full logs are here
prompt output is

Info: Now upgrading nextcloud...
Info: [....................] > Loading installation settings...
Info: [+...................] > Ensuring downward compatibility...
Info: [#+++++++++..........] > Backing up the app before upgrading (may take a while)...
Info: [##########++........] > Upgrading dependencies...
Info: [############........] > Making sure dedicated system user exists...
Info: [############........] > Upgrading PHP-FPM configuration...
Info: [############+.......] > Upgrading NGINX web server configuration...
Info: The service nginx has correctly executed the action reload-or-restart.
Info: [#############+......] > Upgrading Nextcloud...
Warning: [Error] Upgrade failed.
Warning: 144893 Packagers ! Please do not use a separate php ini file, merge your directives in the pool file instead.
Warning: The app was restored to the way it was before the failed upgrade.
Error: Could not upgrade nextcloud: An error occurred inside the app upgrade script
Info: The operation 'Upgrade the 'nextcloud' app' could not be completed. Please share the full log of this operation using the command 'yunohost log share 20220208-185844-app_upgrade-nextcloud' to get help
Warning: Here's an extract of the logs before the crash. It might help debugging the error:
Info: DEBUG - #4 /var/www/nextcloud/lib/private/Server.php(1051): OC\Memcache\Factory->createLocking('lock')
Info: DEBUG - #5 /var/www/nextcloud/lib/private/AppFramework/Utility/SimpleContainer.php(160): OC\Server->OC\{closure}(Object(OC\Server))
Info: DEBUG - #6 /var/www/nextcloud/3rdparty/pimple/pimple/src/Pimple/Container.php(118): OC\AppFramework\Utility\SimpleContainer->OC\AppFramework\Utility\{closure}(Object(Pimple\Container))
Info: DEBUG - #7 /var/www/nextcloud/lib/private/AppFramework/Utility/SimpleContainer.php(127): Pimple\Container->offsetGet('OCP\\Lock\\ILocki...')
Info: DEBUG - #8 /var/www/nextcloud/lib/private/ServerContainer.php(136): OC\AppFramework\Utility\SimpleContainer->query('OCP\\Lock\\ILocki...', false)
Info: DEBUG - #9 /var/www/nextcloud/lib/private/AppFramework/Utility/SimpleContainer.php(56): OC\ServerContainer->query('OCP\\Lock\\ILocki...')
Info: DEBUG - #10 /var/www/nextcloud/lib/private/Server.php(2010): OC\AppFramework\Utility\SimpleContainer->get('OCP\\Lock\\ILocki...')
Info: DEBUG - #11 /var/www/nextcloud/lib/private/Files/View.php(118): OC\Server->getLockingProvider()
Info: DEBUG - #12 /var/www/nextcloud/lib/private/Server.php(433): OC\Files\View->__construct()
Info: DEBUG - #13 /var/www/nextcloud/lib/private/AppFramework/Utility/SimpleContainer.php(160): OC\Server->OC\{closure}(Object(OC\Server))
Info: DEBUG - #14 /var/www/nextcloud/3rdparty/pimple/pimple/src/Pimple/Container.php(118): OC\AppFramework\Utility\SimpleContainer->OC\AppFramework\Utility\{closure}(Object(Pimple\Container))
Info: DEBUG - #15 /var/www/nextcloud/lib/private/AppFramework/Utility/SimpleContainer.php(127): Pimple\Container->offsetGet('OC\\Files\\Node\\H...')
Info: DEBUG - #16 /var/www/nextcloud/lib/private/ServerContainer.php(136): OC\AppFramework\Utility\SimpleContainer->query('OC\\Files\\Node\\H...', false)
Info: DEBUG - #17 /var/www/nextcloud/lib/private/AppFramework/Utility/SimpleContainer.php(56): OC\ServerContainer->query('OC\\Files\\Node\\H...')
Info: DEBUG - #18 /var/www/nextcloud/lib/private/Server.php(1373): OC\AppFramework\Utility\SimpleContainer->get('OC\\Files\\Node\\H...')
Info: DEBUG - #19 /var/www/nextcloud/lib/base.php(594): OC\Server->boot()
Info: DEBUG - #20 /var/www/nextcloud/lib/base.php(1083): OC::init()
Info: DEBUG - #21 /var/www/nextcloud/console.php(48): require_once('/var/www/nextcl...')
Info: DEBUG - #22 /var/www/nextcloud/occ(11): require_once('/var/www/nextcl...')
Info: DEBUG - #23 {main}+ ynh_exit_properly
Warning: unable to upgrade apps: The operation 'Upgrade the 'nextcloud' app' could not be completed. Please share the full log of this operation using the command 'yunohost log share 20220208-185844-app_upgrade-nextcloud' to get help
Error: Some apps could not be upgraded

not sure where to startā€¦

thanks

I guess the main issue is happening here :

2022-02-08 20:00:06,701: DEBUG - An unhandled exception has been thrown:
2022-02-08 20:00:06,702: DEBUG - RedisException: Connection refused in /var/www/nextcloud/lib/private/RedisFactory.php:124
2022-02-08 20:00:06,702: DEBUG - Stack trace:
2022-02-08 20:00:06,702: DEBUG - #0 /var/www/nextcloud/lib/private/RedisFactory.php(124): Redis->connect('localhost', '6379', '0.0', '', 0, 0)
2022-02-08 20:00:06,703: DEBUG - #1 /var/www/nextcloud/lib/private/RedisFactory.php(164): OC\RedisFactory->create()
2022-02-08 20:00:06,703: DEBUG - #2 /var/www/nextcloud/lib/private/Memcache/Redis.php(43): OC\RedisFactory->getInstance()
2022-02-08 20:00:06,703: DEBUG - #3 /var/www/nextcloud/lib/private/Memcache/Factory.php(115): OC\Memcache\Redis->__construct('597061823fab24e...')
2022-02-08 20:00:06,704: DEBUG - #4 /var/www/nextcloud/lib/private/Server.php(1051): OC\Memcache\Factory->createLocking('lock')
2022-02-08 20:00:06,704: DEBUG - #5 /var/www/nextcloud/lib/private/AppFramework/Utility/SimpleContainer.php(160): OC\Server->OC\{closure}(Object(OC\Server))
2022-02-08 20:00:06,704: DEBUG - #6 /var/www/nextcloud/3rdparty/pimple/pimple/src/Pimple/Container.php(118): OC\AppFramework\Utility\SimpleContainer->OC\AppFramework\Utility\{closure}(Object(Pimple\Container))
2022-02-08 20:00:06,705: DEBUG - #7 /var/www/nextcloud/lib/private/AppFramework/Utility/SimpleContainer.php(127): Pimple\Container->offsetGet('OCP\\Lock\\ILocki...')
2022-02-08 20:00:06,705: DEBUG - #8 /var/www/nextcloud/lib/private/ServerContainer.php(136): OC\AppFramework\Utility\SimpleContainer->query('OCP\\Lock\\ILocki...', false)
2022-02-08 20:00:06,705: DEBUG - #9 /var/www/nextcloud/lib/private/AppFramework/Utility/SimpleContainer.php(56): OC\ServerContainer->query('OCP\\Lock\\ILocki...')
2022-02-08 20:00:06,705: DEBUG - #10 /var/www/nextcloud/lib/private/Server.php(2010): OC\AppFramework\Utility\SimpleContainer->get('OCP\\Lock\\ILocki...')
2022-02-08 20:00:06,706: DEBUG - #11 /var/www/nextcloud/lib/private/Files/View.php(118): OC\Server->getLockingProvider()
2022-02-08 20:00:06,706: DEBUG - #12 /var/www/nextcloud/lib/private/Server.php(433): OC\Files\View->__construct()
2022-02-08 20:00:06,706: DEBUG - #13 /var/www/nextcloud/lib/private/AppFramework/Utility/SimpleContainer.php(160): OC\Server->OC\{closure}(Object(OC\Server))
2022-02-08 20:00:06,707: DEBUG - #14 /var/www/nextcloud/3rdparty/pimple/pimple/src/Pimple/Container.php(118): OC\AppFramework\Utility\SimpleContainer->OC\AppFramework\Utility\{closure}(Object(Pimple\Container))
2022-02-08 20:00:06,707: DEBUG - #15 /var/www/nextcloud/lib/private/AppFramework/Utility/SimpleContainer.php(127): Pimple\Container->offsetGet('OC\\Files\\Node\\H...')
2022-02-08 20:00:06,707: DEBUG - #16 /var/www/nextcloud/lib/private/ServerContainer.php(136): OC\AppFramework\Utility\SimpleContainer->query('OC\\Files\\Node\\H...', false)
2022-02-08 20:00:06,707: DEBUG - #17 /var/www/nextcloud/lib/private/AppFramework/Utility/SimpleContainer.php(56): OC\ServerContainer->query('OC\\Files\\Node\\H...')
2022-02-08 20:00:06,708: DEBUG - #18 /var/www/nextcloud/lib/private/Server.php(1373): OC\AppFramework\Utility\SimpleContainer->get('OC\\Files\\Node\\H...')
2022-02-08 20:00:06,708: DEBUG - #19 /var/www/nextcloud/lib/base.php(594): OC\Server->boot()
2022-02-08 20:00:06,708: DEBUG - #20 /var/www/nextcloud/lib/base.php(1083): OC::init()
2022-02-08 20:00:06,709: DEBUG - #21 /var/www/nextcloud/console.php(48): require_once('/var/www/nextcl...')
2022-02-08 20:00:06,709: DEBUG - #22 /var/www/nextcloud/occ(11): require_once('/var/www/nextcl...')
2022-02-08 20:00:06,717: DEBUG - #23 {main}+ ynh_exit_properly

but not sure how to fix that ?

Sounds like redis is down. Can you check the status of redis in the Services page in the webadmin ?

Thanks Aleks for the support.
Indeed, redis and postgresql are not running, it seems to me the issue is a permission issue of the log file/folder.

- Logs begin at Tue 2022-02-08 06:49:16 CET, end at Wed 2022-02-09 07:55:32 CET. --
Feb 08 13:34:40 systemd[1]: redis-server.service: Service RestartSec=100ms expired, scheduling restart.
Feb 08 13:34:40 systemd[1]: redis-server.service: Scheduled restart job, restart counter is at 1.
Feb 08 13:34:40 systemd[1]: Stopped Advanced key-value store.
Feb 08 13:34:40 systemd[1]: Starting Advanced key-value store...
Feb 08 13:34:41 redis-server[25733]: *** FATAL CONFIG FILE ERROR ***
Feb 08 13:34:41 redis-server[25733]: Reading the configuration file, at line 171
Feb 08 13:34:41 redis-server[25733]: >>> 'logfile /var/log/redis/redis-server.log'
Feb 08 13:34:41 redis-server[25733]: Can't open the log file: Permission denied
Feb 08 13:34:41 systemd[1]: redis-server.service: Control process exited, code=exited, status=1/FAILURE
Feb 08 13:34:41 systemd[1]: redis-server.service: Failed with result 'exit-code'.
Feb 08 13:34:41 systemd[1]: Failed to start Advanced key-value store.
Feb 08 13:34:41 systemd[1]: redis-server.service: Service RestartSec=100ms expired, scheduling restart.
Feb 08 13:34:41 systemd[1]: redis-server.service: Scheduled restart job, restart counter is at 2.
Feb 08 13:34:41 systemd[1]: Stopped Advanced key-value store.
Feb 08 13:34:41 systemd[1]: Starting Advanced key-value store...
Feb 08 13:34:41 redis-server[25757]: *** FATAL CONFIG FILE ERROR ***
Feb 08 13:34:41 redis-server[25757]: Reading the configuration file, at line 171
Feb 08 13:34:41 redis-server[25757]: >>> 'logfile /var/log/redis/redis-server.log'
Feb 08 13:34:41 redis-server[25757]: Can't open the log file: Permission denied
Feb 08 13:34:41 systemd[1]: redis-server.service: Control process exited, code=exited, status=1/FAILURE
Feb 08 13:34:41 systemd[1]: redis-server.service: Failed with result 'exit-code'.
Feb 08 13:34:41 systemd[1]: Failed to start Advanced key-value store.
Feb 08 13:34:41 systemd[1]: redis-server.service: Service RestartSec=100ms expired, scheduling restart.
Feb 08 13:34:41 systemd[1]: redis-server.service: Scheduled restart job, restart counter is at 3.
Feb 08 13:34:41 systemd[1]: Stopped Advanced key-value store.
Feb 08 13:34:41 systemd[1]: Starting Advanced key-value store...
Feb 08 13:34:42 redis-server[25760]: *** FATAL CONFIG FILE ERROR ***
Feb 08 13:34:42 redis-server[25760]: Reading the configuration file, at line 171
Feb 08 13:34:42 redis-server[25760]: >>> 'logfile /var/log/redis/redis-server.log'
Feb 08 13:34:42 redis-server[25760]: Can't open the log file: Permission denied
Feb 08 13:34:42 systemd[1]: redis-server.service: Control process exited, code=exited, status=1/FAILURE
Feb 08 13:34:42 systemd[1]: redis-server.service: Failed with result 'exit-code'.
Feb 08 13:34:42 systemd[1]: Failed to start Advanced key-value store.
Feb 08 13:34:42 systemd[1]: redis-server.service: Service RestartSec=100ms expired, scheduling restart.
Feb 08 13:34:42 systemd[1]: redis-server.service: Scheduled restart job, restart counter is at 4.
Feb 08 13:34:42 systemd[1]: Stopped Advanced key-value store.
Feb 08 13:34:42 systemd[1]: Starting Advanced key-value store...
Feb 08 13:34:42 redis-server[25763]: *** FATAL CONFIG FILE ERROR ***
Feb 08 13:34:42 redis-server[25763]: Reading the configuration file, at line 171
Feb 08 13:34:42 redis-server[25763]: >>> 'logfile /var/log/redis/redis-server.log'
Feb 08 13:34:42 redis-server[25763]: Can't open the log file: Permission denied
Feb 08 13:34:42 systemd[1]: redis-server.service: Control process exited, code=exited, status=1/FAILURE
Feb 08 13:34:42 systemd[1]: redis-server.service: Failed with result 'exit-code'.
Feb 08 13:34:42 systemd[1]: Failed to start Advanced key-value store.
Feb 08 13:34:42 systemd[1]: redis-server.service: Service RestartSec=100ms expired, scheduling restart.
Feb 08 13:34:42 systemd[1]: redis-server.service: Scheduled restart job, restart counter is at 5.
Feb 08 13:34:42 systemd[1]: Stopped Advanced key-value store.
Feb 08 13:34:42 systemd[1]: redis-server.service: Start request repeated too quickly.
Feb 08 13:34:42 systemd[1]: redis-server.service: Failed with result 'exit-code'.
Feb 08 13:34:42 systemd[1]: Failed to start Advanced key-value store.

permissions are

drwxr-s---  2 redis adm    4096 Sep 20 00:00 .
drwx------ 22 cedc  cedc   4096 Feb  9 00:00 ..
-rw-rw----  1 redis adm       0 Sep 20 00:00 redis-server.log
-rw-rw----  1 redis adm  868389 Sep 19 11:51 redis-server.log.1.gz
-rw-rw----  1 redis adm   25209 Jun 20  2020 redis-server.log.2.gz
-rw-rw----  1 redis adm   27451 Jun 13  2020 redis-server.log.3.gz

and postgre

drwxrwxr-t  2 root     postgres    4096 Sep 20 00:00 .
drwx------ 22 cedc     cedc        4096 Feb  9 00:00 ..
-rw-r-----  1 postgres adm            0 Sep 20 00:00 postgresql-11-main.log
-rw-r-----  1 postgres adm      5022604 Sep 20 00:00 postgresql-11-main.log.1
-rw-r-----  1 postgres adm        27183 Jun 21  2020 postgresql-11-main.log.2.gz
-rw-r-----  1 postgres adm        27458 Jun 14  2020 postgresql-11-main.log.3.gz

I asume the update is performed by admin and so something like chmod 660 logfile should do the trick ?
Iā€™ll try that and get back to you

edit : well, does not seem to be enough, tried it and then tried to start server andā€¦

Error: "500" Internal Server Error

Action: "PUT" /yunohost/api/services/redis-server/start

Error message:

Could not start the service ā€˜redis-serverā€™
Recent service logs:-- Logs begin at Tue 2022-02-08 06:49:16 CET, end at Wed 2022-02-09 08:07:30 CET. ā€“ Feb 08 13:34:40 systemd[1]: Stopping Advanced key-value storeā€¦ Feb 08 13:34:40 systemd[1]: redis-server.service: Succeeded. Feb 08 13:34:40 systemd[1]: Stopped Advanced key-value store. Feb 08 13:34:40 systemd[1]: Starting Advanced key-value storeā€¦ Feb 08 13:34:40 redis-server[25723]: *** FATAL CONFIG FILE ERROR *** Feb 08 13:34:40 redis-server[25723]: Reading the configuration file, at line 171 Feb 08 13:34:40 redis-server[25723]: >>> ā€˜logfile /var/log/redis/redis-server.logā€™ Feb 08 13:34:40 redis-server[25723]: Canā€™t open the log file: Permission denied Feb 08 13:34:40 systemd[1]: redis-server.service: Control process exited, code=exited, status=1/FAILURE Feb 08 13:34:40 systemd[1]: redis-server.service: Failed with result ā€˜exit-codeā€™. Feb 08 13:34:40 systemd[1]: Failed to start Advanced key-value store. Feb 08 13:34:40 systemd[1]: redis-server.service: Service RestartSec=100ms expired, scheduling restart. Feb 08 13:34:40 systemd[1]: redis-server.service: Scheduled restart job, restart counter is at 1. Feb 08 13:34:40 systemd[1]: Stopped Advanced key-value store. Feb 08 13:34:40 systemd[1]: Starting Advanced key-value storeā€¦ Feb 08 13:34:41 redis-server[25733]: *** FATAL CONFIG FILE ERROR *** Feb 08 13:34:41 redis-server[25733]: Reading the configuration file, at line 171 Feb 08 13:34:41 redis-server[25733]: >>> ā€˜logfile /var/log/redis/redis-server.logā€™ Feb 08 13:34:41 redis-server[25733]: Canā€™t open the log file: Permission denied Feb 08 13:34:41 systemd[1]: redis-server.service: Control process exited, code=exited, status=1/FAILURE Feb 08 13:34:41 systemd[1]: redis-server.service: Failed with result ā€˜exit-codeā€™. Feb 08 13:34:41 systemd[1]: Failed to start Advanced key-value store. Feb 08 13:34:41 systemd[1]: redis-server.service: Service RestartSec=100ms expired, scheduling restart. Feb 08 13:34:41 systemd[1]: redis-server.service: Scheduled restart job, restart counter is at 2. Feb 08 13:34:41 systemd[1]: Stopped Advanced key-value store. Feb 08 13:34:41 systemd[1]: Starting Advanced key-value storeā€¦ Feb 08 13:34:41 redis-server[25757]: *** FATAL CONFIG FILE ERROR *** Feb 08 13:34:41 redis-server[25757]: Reading the configuration file, at line 171 Feb 08 13:34:41 redis-server[25757]: >>> ā€˜logfile /var/log/redis/redis-server.logā€™ Feb 08 13:34:41 redis-server[25757]: Canā€™t open the log file: Permission denied Feb 08 13:34:41 systemd[1]: redis-server.service: Control process exited, code=exited, status=1/FAILURE Feb 08 13:34:41 systemd[1]: redis-server.service: Failed with result ā€˜exit-codeā€™. Feb 08 13:34:41 systemd[1]: Failed to start Advanced key-value store. Feb 08 13:34:41 systemd[1]: redis-server.service: Service RestartSec=100ms expired, scheduling restart. Feb 08 13:34:41 systemd[1]: redis-server.service: Scheduled restart job, restart counter is at 3. Feb 08 13:34:41 systemd[1]: Stopped Advanced key-value store. Feb 08 13:34:41 systemd[1]: Starting Advanced key-value storeā€¦ Feb 08 13:34:42 redis-server[25760]: *** FATAL CONFIG FILE ERROR *** Feb 08 13:34:42 redis-server[25760]: Reading the configuration file, at line 171 Feb 08 13:34:42 redis-server[25760]: >>> ā€˜logfile /var/log/redis/redis-server.logā€™ Feb 08 13:34:42 redis-server[25760]: Canā€™t open the log file: Permission denied Feb 08 13:34:42 systemd[1]: redis-server.service: Control process exited, code=exited, status=1/FAILURE Feb 08 13:34:42 systemd[1]: redis-server.service: Failed with result ā€˜exit-codeā€™. Feb 08 13:34:42 systemd[1]: Failed to start Advanced key-value store. Feb 08 13:34:42 systemd[1]: redis-server.service: Service RestartSec=100ms expired, scheduling restart. Feb 08 13:34:42 systemd[1]: redis-server.service: Scheduled restart job, restart counter is at 4. Feb 08 13:34:42 systemd[1]: Stopped Advanced key-value store. Feb 08 13:34:42 systemd[1]: Starting Advanced key-value storeā€¦ Feb 08 13:34:42 redis-server[25763]: *** FATAL CONFIG FILE ERROR *** Feb 08 13:34:42 redis-server[25763]: Reading the configuration file, at line 171 Feb 08 13:34:42 redis-server[25763]: >>> ā€˜logfile /var/log/redis/redis-server.logā€™ Feb 08 13:34:42 redis-server[25763]: Canā€™t open the log file: Permission denied Feb 08 13:34:42 systemd[1]: redis-server.service: Control process exited, code=exited, status=1/FAILURE Feb 08 13:34:42 systemd[1]: redis-server.service: Failed with result ā€˜exit-codeā€™. Feb 08 13:34:42 systemd[1]: Failed to start Advanced key-value store. Feb 08 13:34:42 systemd[1]: redis-server.service: Service RestartSec=100ms expired, scheduling restart. Feb 08 13:34:42 systemd[1]: redis-server.service: Scheduled restart job, restart counter is at 5. Feb 08 13:34:42 systemd[1]: Stopped Advanced key-value store. Feb 08 13:34:42 systemd[1]: redis-server.service: Start request repeated too quickly. Feb 08 13:34:42 systemd[1]: redis-server.service: Failed with result ā€˜exit-codeā€™. Feb 08 13:34:42 systemd[1]: Failed to start Advanced key-value store. Feb 09 08:07:30 systemd[1]: Starting Advanced key-value storeā€¦ Feb 09 08:07:30 redis-server[12462]: *** FATAL CONFIG FILE ERROR *** Feb 09 08:07:30 redis-server[12462]: Reading the configuration file, at line 171 Feb 09 08:07:30 redis-server[12462]: >>> ā€˜logfile /var/log/redis/redis-server.logā€™ Feb 09 08:07:30 redis-server[12462]: Canā€™t open the log file: Permission denied Feb 09 08:07:30 systemd[1]: redis-server.service: Control process exited, code=exited, status=1/FAILURE Feb 09 08:07:30 systemd[1]: redis-server.service: Failed with result ā€˜exit-codeā€™. Feb 09 08:07:30 systemd[1]: Failed to start Advanced key-value store.

I donā€™t recall playing with permissons so not sure where this comes from

Thatā€™s the problem ā€¦ I donā€™t know who ā€œcedcā€ is and how it became the owner of that directory (/var/log), but that doesnt make sense

The issue lies in both facts that /var/log has no permission for others (---) and the owner/group is cedc. On a ā€œsaneā€ system I have :

$ ls -ld /var/log
drwxr-xr-x 1 root root

Thanks that was the case and also folders in /var/log such as redis one had the same issue

root@oslight:/var/log/postgresql# chmod 761 . 
root@oslight:/var/log/postgresql# ls -la
total 4972
drwxrw---x  2 postgres adm    4096 Sep 20 00:00 .
drwxrw---x 22 root     adm    4096 Feb  9 00:00 ..
-rw-rw----  1 postgres adm       0 Sep 20 00:00 postgresql-11-main.log

resuming the upgrade, crossing fingers ! :crossed_fingers:

This topic was automatically closed 15 days after the last reply. New replies are no longer allowed.