Bug 1583217

Description of problem:

i did backup with plain format and i tried verify mode.

# engine-backup --db-compressor=gzip --mode=verify --file=/tmp/out.backup --log=/tmp/out.log
+ output Verifying:
+ local m=Verifying:
+ log 'OUTPUT: Verifying:'
+ local 'm=OUTPUT: Verifying:'
++ date '+%Y-%m-%d %H:%M:%S'
+ local 'date=2018-05-28 15:11:00'
+ local pid=28628
+ printf '%s\n' '2018-05-28 15:11:00 28628: OUTPUT: Verifying:'
+ printf '%s\n' Verifying:
Verifying:
+ output '- Unpacking file '\''/tmp/out.backup'\'''
+ local 'm=- Unpacking file '\''/tmp/out.backup'\'''
+ log 'OUTPUT: - Unpacking file '\''/tmp/out.backup'\'''
+ local 'm=OUTPUT: - Unpacking file '\''/tmp/out.backup'\'''
++ date '+%Y-%m-%d %H:%M:%S'
+ local 'date=2018-05-28 15:11:00'
+ local pid=28628
+ printf '%s\n' '2018-05-28 15:11:00 28628: OUTPUT: - Unpacking file '\''/tmp/out.backup'\'''
+ printf '%s\n' '- Unpacking file '\''/tmp/out.backup'\'''
- Unpacking file '/tmp/out.backup'
+ log 'Opening tarball /tmp/out.backup to /tmp/engine-backup.actgWtvQIk'
+ local 'm=Opening tarball /tmp/out.backup to /tmp/engine-backup.actgWtvQIk'
++ date '+%Y-%m-%d %H:%M:%S'
+ local 'date=2018-05-28 15:11:00'
+ local pid=28628
+ printf '%s\n' '2018-05-28 15:11:00 28628: Opening tarball /tmp/out.backup to /tmp/engine-backup.actgWtvQIk'
+ tar -C /tmp/engine-backup.actgWtvQIk -pSsxf /tmp/out.backup
+ log 'Verifying md5'
+ local 'm=Verifying md5'
++ date '+%Y-%m-%d %H:%M:%S'
+ local 'date=2018-05-28 15:11:04'
+ local pid=28628
+ printf '%s\n' '2018-05-28 15:11:04 28628: Verifying md5'
+ verifymd5 /tmp/engine-backup.actgWtvQIk md5sum
+ local tardir=/tmp/engine-backup.actgWtvQIk
+ local md5file=md5sum
+ cd /tmp/engine-backup.actgWtvQIk
+ md5sum -c md5sum --status
+ log 'Verifying version'
+ local 'm=Verifying version'
++ date '+%Y-%m-%d %H:%M:%S'
+ local 'date=2018-05-28 15:11:04'
+ local pid=28628
+ printf '%s\n' '2018-05-28 15:11:04 28628: Verifying version'
+ verifyVersion
++ echo 4.2.3.5
++ cut -d . -f 1-2
+ INSTALLED_VERSION=4.2
++ cat /tmp/engine-backup.actgWtvQIk/version
++ cut -d . -f 1-2
+ BACKUP_VERSION=4.2
+ local ok=
+ read validbck validres
+ '[' 4.2 = 3.6 -a 4.2 = 4.0 ']'
+ read validbck validres
+ '[' 4.2 == 4.2 ']'
+ ok=1
+ '[' -z 1 ']'
+ log 'Reading config'
+ local 'm=Reading config'
++ date '+%Y-%m-%d %H:%M:%S'
+ local 'date=2018-05-28 15:11:04'
+ local pid=28628
+ printf '%s\n' '2018-05-28 15:11:04 28628: Reading config'
+ . /tmp/engine-backup.actgWtvQIk/config
++ DB_DUMP_COMPRESSOR=
++ DB_DUMP_FORMAT=plain
++ DWH_DB_DUMP_COMPRESSOR=
++ DWH_DB_DUMP_FORMAT=custom
++ REPORTS_DB_DUMP_COMPRESSOR=
++ REPORTS_DB_DUMP_FORMAT=custom
+ '[' -s /tmp/engine-backup.actgWtvQIk/files ']'
+ '[' -s /tmp/engine-backup.actgWtvQIk/db/engine_backup.db ']'
+ '[' -s /tmp/engine-backup.actgWtvQIk/db/dwh_backup.db ']'
+ '[' -s /tmp/engine-backup.actgWtvQIk/db/reports_backup.db ']'
+ SCOPE_REPORTS_DB=
+ '[' -n 1 -a -n engine ']'
+ output '- Engine database '\''engine'\'''
+ local 'm=- Engine database '\''engine'\'''
+ log 'OUTPUT: - Engine database '\''engine'\'''
+ local 'm=OUTPUT: - Engine database '\''engine'\'''
++ date '+%Y-%m-%d %H:%M:%S'
+ local 'date=2018-05-28 15:11:04'
+ local pid=28628
+ printf '%s\n' '2018-05-28 15:11:04 28628: OUTPUT: - Engine database '\''engine'\'''
+ printf '%s\n' '- Engine database '\''engine'\'''
- Engine database 'engine'
+ log 'Verifying engine database backup at /tmp/engine-backup.actgWtvQIk/db/engine_backup.db'
+ local 'm=Verifying engine database backup at /tmp/engine-backup.actgWtvQIk/db/engine_backup.db'
++ date '+%Y-%m-%d %H:%M:%S'
+ local 'date=2018-05-28 15:11:04'
+ local pid=28628
+ printf '%s\n' '2018-05-28 15:11:04 28628: Verifying engine database backup at /tmp/engine-backup.actgWtvQIk/db/engine_backup.db'
+ verifyEngineDb /tmp/engine-backup.actgWtvQIk/db/engine_backup.db '' plain
+ set -x
+ local backupfile=/tmp/engine-backup.actgWtvQIk/db/engine_backup.db
+ local compressor=
+ local format=plain
+ log 'verifyEngineDb: backupfile /tmp/engine-backup.actgWtvQIk/db/engine_backup.db compressor  format plain'
+ local 'm=verifyEngineDb: backupfile /tmp/engine-backup.actgWtvQIk/db/engine_backup.db compressor  format plain'
++ date '+%Y-%m-%d %H:%M:%S'
+ local 'date=2018-05-28 15:11:04'
+ local pid=28628
+ printf '%s\n' '2018-05-28 15:11:04 28628: verifyEngineDb: backupfile /tmp/engine-backup.actgWtvQIk/db/engine_backup.db compressor  format plain'
+ local pgrestorelog=/tmp/engine-backup.actgWtvQIk/pg-restore-log
+ local vdc_options_dump=/tmp/engine-backup.actgWtvQIk/vdc_options_dump
+ '[' plain = plain ']'
+ '[' -z '' ']'
+ cat /tmp/engine-backup.actgWtvQIk/db/engine_backup.db
+ tee /tmp/out.pgrestore
  ^^ ignore, my hacks
+ awk '/^COPY vdc_options/,/^\\./'
+ cat /tmp/engine-backup.actgWtvQIk/pg-restore-log
+ logdie 'Failed to append pg log to restore log'
+ local 'm=Failed to append pg log to restore log'
+ log 'FATAL: Failed to append pg log to restore log'
+ local 'm=FATAL: Failed to append pg log to restore log'
++ date '+%Y-%m-%d %H:%M:%S'
+ local 'date=2018-05-28 15:11:04'
+ local pid=28628
+ printf '%s\n' '2018-05-28 15:11:04 28628: FATAL: Failed to append pg log to restore log'
+ '[' -n engine -a verify = backup -a -z '' ']'
+ die 'Failed to append pg log to restore log'
+ local 'm=Failed to append pg log to restore log'
+ echo 'FATAL: Failed to append pg log to restore log'
FATAL: Failed to append pg log to restore log
+ exit 1
+ cleanup
+ ec=1
+ source_d cleanup
+ local stage=cleanup
+ local my_cfg_dir=/etc/ovirt-engine-backup/engine-backup-cleanup.d
++ '[' -d /etc/ovirt-engine-backup/engine-backup-cleanup.d ']'
+ '[' -n engine -a 1 = 1 -a verify = backup -a -z '' ']'
+ '[' -n /tmp/engine-backup.actgWtvQIk ']'
+ echo rm -rf /tmp/engine-backup.actgWtvQIk
  ^^^^ ignore, my hacks
rm -rf /tmp/engine-backup.actgWtvQIk


if plain, not populating pgrestorelog?

   1399         if [ "${format}" = "plain" ]; then
   1400                 if [ -z "${compressor}" ]; then
   1401                         cat "${backupfile}"
   1402                 else
   1403                         # Requires the compressor to support '-d'. All our current ones do.
   1404                         "${compressor}" -d < "${backupfile}"
   1405                 fi

thus there's nothing to cat here:

   1417         fi | \
   1418                 tee /tmp/out.pgrestore | awk '/^COPY vdc_options/,/^\\./' > "${vdc_options_dump}"
   1419 
   1420         cat "${pgrestorelog}" >> "${LOG}"  2>&1 \
   1421                 || logdie "Failed to append pg log to restore log"


output of temp dir:

# ls -l /tmp/engine-backup.actgWtvQIk/
total 484
-rw-r--r--. 1 root root    149 May 28 14:59 config
drwxr-xr-x. 2 root root     49 May 28 14:59 db
-rw-r--r--. 1 root root 420832 May 28 14:59 files
-rw-r--r--. 1 root root    273 May 28 14:59 md5sum
-rw-r--r--. 1 root root      8 May 28 14:59 os_version
-rw-r--r--. 1 root root  57226 May 28 15:11 vdc_options_dump
-rw-r--r--. 1 root root      8 May 28 14:59 version

imo there's also something wrong with decompressing:

+ verifyEngineDb /tmp/engine-backup.RJhDOzKWT2/db/engine_backup.db '' plain

it's empty even when one runs verify mode with  --db-compressor=gzip or --archive-compressor=gzip (default for backup seems to be gzip).


Version-Release number of selected component (if applicable):
ovirt-engine-tools-backup-4.2.3.5-0.1.el7.noarch

How reproducible:
100%

Steps to Reproduce:
1. make plain backup (db-dump-format=plain)
2. run verify mode of engine-backup
3.

Actual results:
failure

Expected results:
should work

Additional info:
imo all these compression features are overkill, it is not testable in respect to human resources.

is it mandatory to specify compressor for verify? if so, why? see:

# xdg-mime query filetype /tmp/out.backup
application/x-xz