Description of problem: When trying to restore the DB from nfs, using appliance_console, the rake command is aborted with ---8<---8<--- ArgumentError: wrong number of arguments (given 1, expected 2) ---8<---8<--- and the restore fails Version-Release number of selected component (if applicable): CFME 5.10.0.16, codename: Hammer How reproducible: 3/3 Steps to Reproduce: 1. Backup the DB using pg_dump --format custom --file /tmp/evm_db.backup vmdb_production 2. Drop and create the DB on new machine. dropdb vmdb_production createdb vmdb_production 3. Restore using appliance console ap, 4, 2, nfs_dump_file, y Actual results: Database restore failed. Check the logs for more information # cat /var/www/miq/vmdb/log/appliance_console.log E, [2018-09-27T06:03:50.599861 #55763] ERROR -- : rake aborted! ArgumentError: wrong number of arguments (given 1, expected 2) /opt/rh/cfme-gemset/bundler/gems/cfme-gems-pending-5ad643269371/lib/gems/pending/util/miq_file_storage.rb:141:in `download' /var/www/miq/vmdb/lib/evm_database_ops.rb:146:in `block in with_file_storage' /opt/rh/cfme-gemset/bundler/gems/cfme-gems-pending-5ad643269371/lib/gems/pending/util/miq_file_storage.rb:31:in `with_interface_class' /var/www/miq/vmdb/lib/evm_database_ops.rb:130:in `with_file_storage' /var/www/miq/vmdb/lib/evm_database_ops.rb:92:in `restore' /var/www/miq/vmdb/lib/tasks/evm_dba.rake:261:in `block (4 levels) in <top (required)>' /opt/rh/cfme-gemset/gems/rake-12.3.1/exe/rake:27:in `<top (required)>' Tasks: TOP => evm:db:restore:remote (See full trace by running task with --trace) Expected results: db restored Additional info:
partial fix: https://github.com/ManageIQ/manageiq/pull/18144
New commit detected on ManageIQ/manageiq/hammer: https://github.com/ManageIQ/manageiq/commit/92dd1890250e22e705503601ae2f5397faf3b842 commit 92dd1890250e22e705503601ae2f5397faf3b842 Author: Nick Carboni <ncarboni> AuthorDate: Mon Nov 5 17:25:17 2018 -0500 Commit: Nick Carboni <ncarboni> CommitDate: Mon Nov 5 17:25:17 2018 -0500 Merge pull request #18144 from NickLaMuro/fix_miq_file_storage_send_args_for_download Fix send_args for EvmDatabaseOps.restore (cherry picked from commit 1775555cfe823ffd5c3c3c50137761c43cf49827) https://bugzilla.redhat.com/show_bug.cgi?id=1633573 https://bugzilla.redhat.com/show_bug.cgi?id=1513520 lib/evm_database_ops.rb | 7 + spec/lib/evm_database_ops_spec.rb | 2 +- 2 files changed, 8 insertions(+), 1 deletion(-)
The following have been merged: https://github.com/ManageIQ/manageiq-gems-pending/pull/385 https://github.com/ManageIQ/manageiq-gems-pending/pull/389 https://github.com/ManageIQ/manageiq-gems-pending/pull/390 https://github.com/ManageIQ/manageiq-gems-pending/pull/395 https://github.com/ManageIQ/manageiq-gems-pending/pull/396 https://github.com/ManageIQ/manageiq-gems-pending/pull/397 https://github.com/ManageIQ/manageiq-gems-pending/pull/398 https://github.com/ManageIQ/manageiq-gems-pending/pull/399 https://github.com/ManageIQ/manageiq-gems-pending/pull/400 https://github.com/ManageIQ/manageiq-gems-pending/pull/401 https://github.com/ManageIQ/manageiq-gems-pending/pull/402 https://github.com/ManageIQ/manageiq-gems-pending/pull/405 https://github.com/ManageIQ/manageiq-gems-pending/pull/406 https://github.com/ManageIQ/manageiq-gems-pending/pull/410 https://github.com/ManageIQ/manageiq/pull/18144 https://github.com/ManageIQ/manageiq/pull/18166 https://github.com/ManageIQ/manageiq/pull/18167 Which should now fix the issue reported (and further ones not reported as well) regarding database restores.
I couldn't restore the db backup created by: # ap 4) Create Database Backup 2) Network File System (NFS) When I select: # ap 6) Restore Database From Backup 2) Network File System (NFS) Enter the location of the remote backup file Example: nfs://host.mydomain.com/exported/my_exported_folder/db.backup: nfs://52.13.32.199/srv/export/db_backup/tmp/evm_db.backup I get: Restoring the database... Database restore failed. Check the logs for more information Press any key to continue. # cat /var/www/miq/vmdb/log/appliance_console.log # Logfile created on 2019-02-22 09:25:10 -0500 by logger.rb/56815 E, [2019-02-22T09:25:10.465108 #17676] ERROR -- : rake aborted! IOError: closed stream /opt/rh/cfme-gemset/bundler/gems/cfme-gems-pending-71d6e5aabd0b/lib/gems/pending/util/mount/miq_generic_mount_session.rb:304:in `copy_stream' /opt/rh/cfme-gemset/bundler/gems/cfme-gems-pending-71d6e5aabd0b/lib/gems/pending/util/mount/miq_generic_mount_session.rb:304:in `download_single' /opt/rh/cfme-gemset/bundler/gems/cfme-gems-pending-71d6e5aabd0b/lib/gems/pending/util/miq_file_storage.rb:145:in `download' /var/www/miq/vmdb/lib/evm_database_ops.rb:166:in `block in with_file_storage' /opt/rh/cfme-gemset/bundler/gems/cfme-gems-pending-71d6e5aabd0b/lib/gems/pending/util/miq_file_storage.rb:31:in `with_interface_class' /var/www/miq/vmdb/lib/evm_database_ops.rb:139:in `with_file_storage' /var/www/miq/vmdb/lib/evm_database_ops.rb:92:in `restore' /var/www/miq/vmdb/lib/tasks/evm_dba.rake:263:in `block (4 levels) in <top (required)>' /opt/rh/cfme-gemset/gems/rake-12.3.2/exe/rake:27:in `<top (required)>' Tasks: TOP => evm:db:restore:remote (See full trace by running task with --trace) ==> /var/www/miq/vmdb/log/evm.log <== [----] I, [2019-02-22T09:25:05.605769 #18021:f62f48] INFO -- : MIQ(MiqNfsSession-mount_share) Connecting to host: [52.13.32.199], share: [/srv/export/db_backup/tmp]...Complete [----] I, [2019-02-22T09:25:05.606744 #18021:f62f48] INFO -- : MIQ(MiqNfsSession-relative_to_mount) mount point [/srv/export/db_backup/tmp], uri: [nfs://52.13.32.199/srv/export/db_backup/tmp/evm_db.backup]... [----] I, [2019-02-22T09:25:05.607008 #18021:f62f48] INFO -- : MIQ(MiqNfsSession-relative_to_mount) mount point [/srv/export/db_backup/tmp], uri: [nfs://52.13.32.199/srv/export/db_backup/tmp/evm_db.backup]...relative: [evm_db.backup] [----] I, [2019-02-22T09:25:05.805155 #18021:f62f48] INFO -- : MIQ(MiqNfsSession-download) Copying file [/tmp/miq_20190222-18021-8hhig9/evm_db.backup] to [#<StringIO:0x00000000086ec9b0>]... [----] I, [2019-02-22T09:25:06.325386 #18021:f62f48] INFO -- : MIQ(MiqNfsSession-download) Copying file [/tmp/miq_20190222-18021-8hhig9/evm_db.backup] to [#<StringIO:0x00000000086ec9b0>] complete [----] I, [2019-02-22T09:25:06.325576 #18021:f62f48] INFO -- : MIQ(Class-disconnect) Disconnecting mount point: /tmp/miq_20190222-18021-8hhig9 [----] I, [2019-02-22T09:25:06.667897 #18021:f62f48] INFO -- : MIQ(Class-disconnect) Disconnecting mount point: /tmp/miq_20190222-18021-8hhig9...Complete [----] I, [2019-02-22T09:25:06.668121 #18021:f62f48] INFO -- : MIQ(MiqNfsSession-download) Download File: [nfs://52.13.32.199/srv/export/db_backup/tmp/evm_db.backup] complete [----] I, [2019-02-22T09:25:06.669654 #18021:f62f48] INFO -- : MIQ(MiqNfsSession-download) Target: [#<File:0x0000000001eb6238>], Remote file: [nfs://52.13.32.199/srv/export/db_backup/tmp/evm_db.backup]... [----] I, [2019-02-22T09:25:06.687254 #18021:f62f48] INFO -- : MIQ(MiqNfsSession-mount_share) Connecting to host: [52.13.32.199], share: [/srv/export/db_backup/tmp] using mount point: [/tmp/miq_20190222-18021-1ozbrxv]... [----] E, [2019-02-22T09:25:06.799746 #18021:f5b0f4] ERROR -- : MIQ(EvmDatabaseOps.prepare_for_restore) Database restore failed. Shut down all evmserverd processes before attempting a database restore [----] I, [2019-02-22T09:25:07.091897 #14338:c52f60] INFO -- : MIQ(MiqScheduleWorker::Runner#do_work) Number of scheduled items to be processed: 1. [----] I, [2019-02-22T09:25:09.527484 #18021:f62f48] INFO -- : MIQ(MiqNfsSession-mount_share) Connecting to host: [52.13.32.199], share: [/srv/export/db_backup/tmp]...Complete [----] I, [2019-02-22T09:25:09.527780 #18021:f62f48] INFO -- : MIQ(MiqNfsSession-relative_to_mount) mount point [/srv/export/db_backup/tmp], uri: [nfs://52.13.32.199/srv/export/db_backup/tmp/evm_db.backup]... [----] I, [2019-02-22T09:25:09.528006 #18021:f62f48] INFO -- : MIQ(MiqNfsSession-relative_to_mount) mount point [/srv/export/db_backup/tmp], uri: [nfs://52.13.32.199/srv/export/db_backup/tmp/evm_db.backup]...relative: [evm_db.backup] [----] I, [2019-02-22T09:25:09.727937 #18021:f62f48] INFO -- : MIQ(MiqNfsSession-download) Copying file [/tmp/miq_20190222-18021-1ozbrxv/evm_db.backup] to [#<File:0x0000000001eb6238>]... [----] E, [2019-02-22T09:25:10.029479 #18021:f62f48] ERROR -- : MIQ(MiqNfsSession-download) Downloading [nfs://52.13.32.199/srv/export/db_backup/tmp/evm_db.backup] to [#<File:0x0000000001eb6238>], failed due to error: 'closed stream' [----] I, [2019-02-22T09:25:10.029880 #18021:f62f48] INFO -- : MIQ(Class-disconnect) Disconnecting mount point: /tmp/miq_20190222-18021-1ozbrxv [----] I, [2019-02-22T09:25:10.366827 #18021:f62f48] INFO -- : MIQ(Class-disconnect) Disconnecting mount point: /tmp/miq_20190222-18021-1ozbrxv...Complete
Aha. I had to first shut the evmserver down. Then I get: Restore Database From Backup Note: A database restore cannot be undone. The restore will use the file: nfs://A.B.C.D/srv/export/db_backup/tmp/evm_db.backup. Are you sure you would like to restore the database? (Y/N): y Restoring the database... Press any key to continue. [root@host-192-168-100-40 ~]# tail -fn0 /var/www/miq/vmdb/log/appliance_console.log /var/www/miq/vmdb/log/evm.log | tee logs ==> /var/www/miq/vmdb/log/appliance_console.log <== ==> /var/www/miq/vmdb/log/evm.log <== [----] I, [2019-02-22T09:48:11.757906 #32437:101af58] INFO -- : MIQ(Vmdb::Loggers.apply_config) Log level for azure.log has been changed to [WARN] [----] I, [2019-02-22T09:48:11.758272 #32437:101af58] INFO -- : MIQ(Vmdb::Loggers.apply_config) Log level for vim.log has been changed to [WARN] [----] I, [2019-02-22T09:48:12.428801 #32437:101af58] INFO -- : MIQ(SessionStore) Using session_store: ActionDispatch::Session::MemCacheStore [----] I, [2019-02-22T09:48:12.899067 #32437:101af58] INFO -- : MIQ(Vmdb::Initializer.init) - Program Name: /opt/rh/cfme-gemset/bin/rake, PID: 32437, ENV['EVMSERVER']: [----] I, [2019-02-22T09:48:20.273890 #32437:101af58] INFO -- : MIQ(MiqNfsSession-download) Target: [#<StringIO:0x000000000b459e70>], Remote file: [nfs://52.13.32.199/srv/export/db_backup/tmp/evm_db.backup]... [----] I, [2019-02-22T09:48:20.292413 #32437:101af58] INFO -- : MIQ(MiqNfsSession-mount_share) Connecting to host: [52.13.32.199], share: [/srv/export/db_backup/tmp] using mount point: [/tmp/miq_20190222-32437-15iedql]... [----] I, [2019-02-22T09:48:22.908862 #32437:101af58] INFO -- : MIQ(MiqNfsSession-mount_share) Connecting to host: [52.13.32.199], share: [/srv/export/db_backup/tmp]...Complete [----] I, [2019-02-22T09:48:22.909107 #32437:101af58] INFO -- : MIQ(MiqNfsSession-relative_to_mount) mount point [/srv/export/db_backup/tmp], uri: [nfs://A.B.C.D/srv/export/db_backup/tmp/evm_db.backup]... [----] I, [2019-02-22T09:48:22.909338 #32437:101af58] INFO -- : MIQ(MiqNfsSession-relative_to_mount) mount point [/srv/export/db_backup/tmp], uri: [nfs://A.B.C.D/srv/export/db_backup/tmp/evm_db.backup]...relative: [evm_db.backup] [----] I, [2019-02-22T09:48:23.092624 #32437:101af58] INFO -- : MIQ(MiqNfsSession-download) Copying file [/tmp/miq_20190222-32437-15iedql/evm_db.backup] to [#<StringIO:0x000000000b459e70>]... [----] I, [2019-02-22T09:48:23.571408 #32437:101af58] INFO -- : MIQ(MiqNfsSession-download) Copying file [/tmp/miq_20190222-32437-15iedql/evm_db.backup] to [#<StringIO:0x000000000b459e70>] complete [----] I, [2019-02-22T09:48:23.571672 #32437:101af58] INFO -- : MIQ(Class-disconnect) Disconnecting mount point: /tmp/miq_20190222-32437-15iedql [----] I, [2019-02-22T09:48:23.893404 #32437:101af58] INFO -- : MIQ(Class-disconnect) Disconnecting mount point: /tmp/miq_20190222-32437-15iedql...Complete [----] I, [2019-02-22T09:48:23.893659 #32437:101af58] INFO -- : MIQ(MiqNfsSession-download) Download File: [nfs://52.13.32.199/srv/export/db_backup/tmp/evm_db.backup] complete [----] I, [2019-02-22T09:48:23.894998 #32437:101af58] INFO -- : MIQ(MiqNfsSession-download) Target: [#<File:0x0000000002020358>], Remote file: [nfs://52.13.32.199/srv/export/db_backup/tmp/evm_db.backup]... [----] I, [2019-02-22T09:48:23.895767 #32437:101af58] INFO -- : MIQ(MiqNfsSession-mount_share) Connecting to host: [52.13.32.199], share: [/srv/export/db_backup/tmp] using mount point: [/tmp/miq_20190222-32437-1q7b41p]... [----] I, [2019-02-22T09:48:26.578809 #32437:101af58] INFO -- : MIQ(MiqNfsSession-mount_share) Connecting to host: [52.13.32.199], share: [/srv/export/db_backup/tmp]...Complete [----] I, [2019-02-22T09:48:26.579052 #32437:101af58] INFO -- : MIQ(MiqNfsSession-relative_to_mount) mount point [/srv/export/db_backup/tmp], uri: [nfs://52.13.32.199/srv/export/db_backup/tmp/evm_db.backup]... [----] I, [2019-02-22T09:48:26.579249 #32437:101af58] INFO -- : MIQ(MiqNfsSession-relative_to_mount) mount point [/srv/export/db_backup/tmp], uri: [nfs://52.13.32.199/srv/export/db_backup/tmp/evm_db.backup]...relative: [evm_db.backup] [----] I, [2019-02-22T09:48:26.767724 #32437:101af58] INFO -- : MIQ(MiqNfsSession-download) Copying file [/tmp/miq_20190222-32437-1q7b41p/evm_db.backup] to [#<File:0x0000000002020358>]... [----] I, [2019-02-22T09:48:31.258798 #32437:101af58] INFO -- : MIQ(MiqNfsSession-download) Copying file [/tmp/miq_20190222-32437-1q7b41p/evm_db.backup] to [#<File:0x0000000002020358>] complete [----] I, [2019-02-22T09:48:31.259487 #32437:101af58] INFO -- : MIQ(Class-disconnect) Disconnecting mount point: /tmp/miq_20190222-32437-1q7b41p [----] I, [2019-02-22T09:48:31.587402 #32437:101af58] INFO -- : MIQ(Class-disconnect) Disconnecting mount point: /tmp/miq_20190222-32437-1q7b41p...Complete [----] I, [2019-02-22T09:48:31.587577 #32437:101af58] INFO -- : MIQ(MiqNfsSession-download) Download File: [nfs://52.13.32.199/srv/export/db_backup/tmp/evm_db.backup] complete [----] I, [2019-02-22T09:48:39.765982 #32437:101af58] INFO -- : MIQ(EvmDatabaseOps.restore) [vmdb_production] database has been restored from file: [nfs://A.B.C.D/srv/export/db_backup/tmp/evm_db.backup]