Restauration de backup qui n'abouti pas

BeauFort9476 · Mai 26, 2024, 3:09

Hello la communauté,

je tente une restauration de backup sur mon Jeedom installé sur VM Freebox Delta.

Jusqu’à présent je n’avais pas de soucis, mais là après plusieurs tentatives la procédure de restauration bloque sur l’étape Unpacking backup:

PHP Warning:  PHP Startup: Unable to load dynamic library 'mosquitto.so' (tried: /usr/lib/php/20180731/mosquitto.so (/usr/lib/php/20180731/mosquitto.so: cannot open shared object file: No such file or directory), /usr/lib/php/20180731/mosquitto.so.so (/usr/lib/php/20180731/mosquitto.so.so: cannot open shared object file: No such file or directory)) in Unknown on line 0
[START RESTORE]
***************Begin Jeedom restore 2024-05-26 16:45:56***************
Send begin restore event...OK
Checking rights...
OK
Restore from file : /var/www/html/core/class/../../backup/backup-Jeedom_Synology-4.4.6-2024-05-26-16h36.tar.gz
Backup database access configuration...OK
Disable all task OK
Disable all scenario OK
Unpacking backup...

Et pas plus d’information depuis plusieurs minutes.
Où pourrais-je trouver plus de traces sur le déroulement de la procédure de restauration?

En effet le fichier restore des logs n’est plus accessible:

Je peux encore me connecter en ssh à ma VM, puis-je trouver des traces intéressantes sur ce processus?

Merci d’avance

Loic · Mai 26, 2024, 3:33

Bonjour
Attends un peu ça peut prendre jusqu’à 1h la l’erreur c’est je suis en train de restorer ça a pas fini il me manque encore des tables. Tu peux suivre le log en ssh il est dans /var/www/html/log

BeauFort9476 · Mai 26, 2024, 3:49

Ok, merci @Loic

freebox@Jeedom-VM:/var/www/html/log$ date
Sun 26 May 2024 03:47:32 PM UTC
freebox@Jeedom-VM:/var/www/html/log$ more restore
PHP Warning:  PHP Startup: Unable to load dynamic library 'mosquitto.so' (tried: /usr/lib/php/20180731/mosquitto.so (/usr/lib/php/20180731/mosquitto.so: cannot open shared object file: No such file
or directory), /usr/lib/php/20180731/mosquitto.so.so (/usr/lib/php/20180731/mosquitto.so.so: cannot open shared object file: No such file or directory)) in Unknown on line 0
[START RESTORE]
***************Begin Jeedom restore 2024-05-26 16:45:56***************
Send begin restore event...OK
Checking rights...
OK
Restore from file : /var/www/html/core/class/../../backup/backup-Jeedom_Synology-4.4.6-2024-05-26-16h36.tar.gz
Backup database access configuration...OK
Disable all task OK
Disable all scenario OK
Unpacking backup...
OK
Deleting database...Disabling constraints...OK
Deleting table : cmd ...OK
Deleting table : config ...OK
Deleting table : cron ...OK
Deleting table : dataStore ...OK
Deleting table : data_amfj ...OK
Deleting table : eqLogic ...OK
Deleting table : eqReal ...OK
Deleting table : history ...OK
Deleting table : historyArch ...OK
Deleting table : interactDef ...OK
Deleting table : interactQuery ...OK
Deleting table : listener ...OK
Deleting table : message ...OK
Deleting table : note ...OK
Deleting table : object ...OK
Deleting table : plan ...OK
Deleting table : plan3d ...OK
Deleting table : plan3dHeader ...OK
Deleting table : planHeader ...OK
Deleting table : scenario ...OK
Deleting table : scenarioElement ...OK
Deleting table : scenarioExpression ...OK
Deleting table : scenarioSubElement ...OK
Deleting table : timeline ...OK
Deleting table : update ...OK
Deleting table : user ...OK
Deleting table : view ...OK
Deleting table : viewData ...OK
Deleting table : viewZone ...OK
Deleting table : widgets ...OK
Restoring database from backup...

J’ai l’impression que le contenu de la log n’a pas bougé depuis 1h:
-rw-rw-r-- 1 www-data www-data 1778 May 26 14:47 restore

Loic · Mai 26, 2024, 3:50

Ben là il restore la base. Tu dois pouvoir voir les process qui tournent pour valider

BeauFort9476 · Mai 26, 2024, 3:51

@Loic , voilà ce que top me remonte:

top - 15:51:02 up 2:41, 1 user, load average: 0.59, 0.77, 0.86
Tasks: 127 total, 10 running, 116 sleeping, 0 stopped, 1 zombie
%Cpu(s): 39.1 us, 14.0 sy, 0.0 ni, 46.2 id, 0.0 wa, 0.0 hi, 0.7 si, 0.0 st
MiB Mem : 3947.8 total, 665.9 free, 719.7 used, 2562.2 buff/cache
MiB Swap: 1024.0 total, 1024.0 free, 0.0 used. 2960.7 avail Mem

PID USER 13635 www-data 20 13639 www-data 20 13690 www-data 20 13703 www-data 20 13715 www-data 20 13375 www-data 20 13727 www-data 20 13379 www-data 20 558 root 693 mysql 13390 www-data 20 7335 root 10 root 20 0 17 root 20 0 587 ntp 1901 www-data 20 12448 root 20 0 13395 www-data 20 13397 www-data 20 1 root 2 root 20 0 3 root 0 -20 4 root 0 -20 6 root 0 -20 8 root 0 -20 9 root 20 0 11 root 20 0 12 root rt 0 14 root 20 0 15 root 20 0 16 root rt 0 19 root 0 -20 20 root 20 0 21 root 0 -20 22 root 20 0 24 root 20 0 25 root 20 0 26 root 0 -20 27 root 20 0 28 root 25 5 29 root 39 19 30 root 0 -20 31 root 0 -20 32 root 0 -20 33 root 0 -20 34 root 0 -20 35 root rt 0 38 root 20 0 56 root 0 -20 57 root 0 -20 59 root 0 -20 68 root 0 -20 71 root -51 0 113 root 0 -20 114 root 20 0 115 root 0 -20 139 root 0 -20 143 root 0 -20 145 root 20 0 146 root 0 -20 157 root 20 0 PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
0 175500 51552 30196 R 16.7 1.3 0:00.50 ffmpeg
0 219676 35632 26076 S 10.3 0.9 0:00.31 php
0 219688 37384 27832 R 9.7 0.9 0:00.29 php
0 219688 36324 26772 R 7.3 0.9 0:00.22 php
0 217628 32800 25304 R 5.0 0.8 0:00.15 php
0 231372 35268 18000 S 2.7 0.9 0:00.46 apache2
0 217432 30840 23512 R 2.0 0.8 0:00.06 php
0 231360 33416 16152 S 1.3 0.8 0:00.73 apache2
20 0 691456 22984 8916 S 1.0 0.6 0:54.12 fail2ban-server
20 0 1608060 182484 17208 S 1.0 4.5 1:54.46 mysqld
0 225444 28844 17420 S 1.0 0.7 0:00.24 apache2
20 0 4876036 86560 37548 S 0.7 2.1 0:28.66 node
0 0 0 I 0.3 0.0 0:10.61 rcu_sched
0 0 0 R 0.3 0.0 0:00.70 ksoftirqd/1
20 0 73612 3080 2568 S 0.3 0.1 0:00.81 ntpd
0 630776 33432 8240 S 0.3 0.8 0:18.89 python3
0 0 0 I 0.3 0.0 0:00.01 kworker/1:1-events
0 231340 32924 15728 S 0.3 0.8 0:00.39 apache2
0 224376 27812 17468 S 0.3 0.7 0:00.09 apache2
20 0 99788 9504 7064 S 0.0 0.2 0:03.69 systemd
0 0 0 S 0.0 0.0 0:00.01 kthreadd
0 0 0 I 0.0 0.0 0:00.00 rcu_gp
0 0 0 I 0.0 0.0 0:00.00 rcu_par_gp
0 0 0 I 0.0 0.0 0:00.00 kworker/0:0H
0 0 0 I 0.0 0.0 0:00.00 mm_percpu_wq
0 0 0 S 0.0 0.0 0:03.17 ksoftirqd/0
0 0 0 I 0.0 0.0 0:00.00 rcu_bh
0 0 0 S 0.0 0.0 0:00.11 migration/0
0 0 0 S 0.0 0.0 0:00.04 cpuhp/0
0 0 0 S 0.0 0.0 0:00.00 cpuhp/1
0 0 0 S 0.0 0.0 0:00.10 migration/1
0 0 0 I 0.0 0.0 0:00.00 kworker/1:0H-kblockd
0 0 0 S 0.0 0.0 0:00.00 kdevtmpfs
0 0 0 I 0.0 0.0 0:00.00 netns
0 0 0 S 0.0 0.0 0:00.02 kauditd
0 0 0 S 0.0 0.0 0:00.00 khungtaskd
0 0 0 S 0.0 0.0 0:00.00 oom_reaper
0 0 0 I 0.0 0.0 0:00.00 writeback
0 0 0 S 0.0 0.0 0:00.00 kcompactd0
0 0 0 S 0.0 0.0 0:00.00 ksmd
0 0 0 S 0.0 0.0 0:01.61 khugepaged
0 0 0 I 0.0 0.0 0:00.00 crypto
0 0 0 I 0.0 0.0 0:00.00 kintegrityd
0 0 0 I 0.0 0.0 0:00.00 kblockd
0 0 0 I 0.0 0.0 0:00.00 edac-poller
0 0 0 I 0.0 0.0 0:00.00 devfreq_wq
0 0 0 S 0.0 0.0 0:00.00 watchdogd
0 0 0 S 0.0 0.0 0:00.00 kswapd0
0 0 0 I 0.0 0.0 0:00.00 kthrotld
0 0 0 I 0.0 0.0 0:00.00 acpi_thermal_pm
0 0 0 I 0.0 0.0 0:00.00 ipv6_addrconf
0 0 0 I 0.0 0.0 0:00.00 kstrp
0 0 0 S 0.0 0.0 0:00.00 irq/43-ACPI:Eve
0 0 0 I 0.0 0.0 0:02.30 kworker/0:1H-kblockd
0 0 0 S 0.0 0.0 0:00.00 scsi_eh_0
0 0 0 I 0.0 0.0 0:00.00 scsi_tmf_0
0 0 0 I 0.0 0.0 0:00.88 kworker/1:1H-kblockd
0 0 0 I 0.0 0.0 0:00.00 kworker/u5:0
0 0 0 S 0.0 0.0 0:03.93 jbd2/vda2-8
0 0 0 I 0.0 0.0 0:00.00 ext4-rsv-conver
0 0 0 S 0.0 0.0 0:00.02 hwrng

Le démon MySQL ne semble pas super chargé…

Je tente la même procédure de restauration depuis une toute nouvelle VM… pour comparer et déjà le message la console va plus loin alors qu’il en est à la même étape de restauration de la DB dans les logs…

Et là le processus Mysqld bosse à fond!
top - 16:09:15 up 13 min, 1 user, load average: 8.00, 4.70, 2.33
Tasks: 143 total, 18 running, 125 sleeping, 0 stopped, 0 zombie
%Cpu(s): 83.0 us, 17.0 sy, 0.0 ni, 0.0 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st
MiB Mem : 2749.2 total, 74.0 free, 556.3 used, 2118.8 buff/cache
MiB Swap: 1024.0 total, 1023.5 free, 0.5 used. 1970.0 avail Mem

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
771 mysql 20 0 1145548 224844 16924 S 10.3 8.0 1:07.69 mysqld
8105 root 20 0 30520 25072 7500 R 5.3 0.9 0:01.60 pip3
8281 www-data 20 0 219296 40980 31376 R 5.0 1.5 0:00.59 php
8313 www-data 20 0 219268 39100 29556 R 5.0 1.4 0:00.46 php
8369 www-data 20 0 219416 36340 26812 R 5.0 1.3 0:00.27 php
8402 www-data 20 0 219340 35504 25984 R 5.0 1.3 0:00.20 php
8421 www-data 20 0 217192 33080 25620 R 5.0 1.2 0:00.16 php
8243 www-data 20 0 219240 42132 32524 R 4.7 1.5 0:00.66 php
8335 www-data 20 0 219228 37400 27880 R 4.7 1.3 0:00.34 php
8377 www-data 20 0 219300 36140 26620 R 4.7 1.3 0:00.26 php
8381 www-data 20 0 219300 36220 26700 R 4.7 1.3 0:00.26 php
8383 www-data 20 0 219228 35988 26464 S 4.7 1.3 0:00.24 php
8359 www-data 20 0 219228 36688 27176 S 4.4 1.3 0:00.28 php
8441 www-data 20 0 217036 31300 23884 R 3.8 1.1 0:00.12 php
8342 www-data 20 0 219228 36916 27396 S 3.1 1.3 0:00.29 php
766 www-data 20 0 221372 25660 16840 R 2.8 0.9 0:01.53 apache2
8466 www-data 20 0 217000 30864 23460 R 1.9 1.1 0:00.06 php

Et sur cette VM vierge, la restauration avance bien plus vite:

Disable all scenario OK
Unpacking backup...
OK
Deleting database...Disabling constraints...OK
Deleting table : cmd ...
OK
Deleting table : config ...OK
Deleting table : cron ...OK
Deleting table : dataStore ...OK
Deleting table : eqLogic ...OK
Deleting table : eqReal ...OK
Deleting table : history ...OK
Deleting table : historyArch ...OK
Deleting table : interactDef ...OK
Deleting table : interactQuery ...OK
Deleting table : listener ...OK
Deleting table : message ...OK
Deleting table : note ...OK
Deleting table : object ...OK
Deleting table : plan ...OK
Deleting table : plan3d ...OK
Deleting table : plan3dHeader ...OK
Deleting table : planHeader ...OK
Deleting table : scenario ...OK
Deleting table : scenarioElement ...OK
Deleting table : scenarioExpression ...OK
Deleting table : scenarioSubElement ...OK
Deleting table : timeline ...OK
Deleting table : update ...OK
Deleting table : user ...OK
Deleting table : view ...OK
Deleting table : viewData ...OK
Deleting table : viewZone ...OK
Deleting table : widgets ...OK
Restoring database from backup...OK
Enable back constraints...OK
Restoring cache...OK

 sudo: yarn: command not found
dpkg-query: package 'netcat' is not installed and no information is available
Use dpkg --info (= dpkg-deb --info) to examine archive files.
Check jeedom consistency...[START CONSISTENCY]
[START CHECK AND FIX DB]

Fix : ALTER TABLE `cmd` DROP INDEX `logicalID`;
Fix :
CREATE INDEX `logicalID` ON `cmd` (`logicalId` ASC)
Fix : CREATE INDEX `logicalID` ON `cmd` (`logicalId` ASC)***ERROR*** [MySQL] Error code : 42000 (1071). Specified key was too long; max key length is 3072 byte
s  : CREATE INDEX `logicalID` ON `cmd` (`logicalId` ASC)

[END CHECK AND FIX DB]
Check jeedom package...***ERROR*** Installation de package impossible car il y a déjà une installation en cours
Check jeedom database...
Fix : CREATE INDEX `logicalID` ON `cmd` (`logicalId` ASC)
Fix : CREATE INDEX `logicalID` ON `cmd` (`logicalId` ASC)***ERROR*** [MySQL] Error code : 42000 (1071). Specified key was too long; max key length is 3072 byte
s  : CREATE INDEX `logicalID` ON `cmd` (`logicalId` ASC)

Check crons...

Check filesystem right...

BeauFort9476 · Mai 26, 2024, 5:34

Réinstallation from scratch réussie.
En faisant une vérification d’intégrité j’ai cette erreur:

Check jeedom database...
Fix : CREATE INDEX `logicalID` ON `cmd` (`logicalId` ASC)
Fix : CREATE INDEX `logicalID` ON `cmd` (`logicalId` ASC)***ERROR*** [MySQL] Error code : 42000 (1071). Specified key was too long; max key length is 3072 bytes  : CREATE INDEX `logicalID` ON `cmd` (`logicalId` ASC)
Check crons...
Check filesystem right...

Est-ce grave docteur?
@Loic quelquechose à faire pour corriger?

Loic · Mai 26, 2024, 6:10

Bonjour
Tu peux ignorer c’est spécifique debian 12.

system · Mai 31, 2024, 10:26

Ce sujet a été automatiquement fermé après 24 heures suivant le dernier commentaire. Aucune réponse n’est permise dorénavant.