Bug 1717025

New commit detected on ManageIQ/manageiq/hammer:

https://github.com/ManageIQ/manageiq/commit/c3c65b640900e0e5381c91a43ba414cb647d770a
commit c3c65b640900e0e5381c91a43ba414cb647d770a
Author:     Nick Carboni <ncarboni>
AuthorDate: Fri May 17 11:39:09 2019 -0400
Commit:     Nick Carboni <ncarboni>
CommitDate: Fri May 17 11:39:09 2019 -0400

    Merge pull request #18745 from NickLaMuro/fix_database_backup_diskspace_check

    [EvmDatabaseOps] Fix .validate_free_space target

    (cherry picked from commit 6642bf629f9e642e3cc8665d6ca52580f3e2c01d)

    Fixes https://bugzilla.redhat.com/show_bug.cgi?id=1717025

 lib/evm_database_ops.rb | 16 +-
 spec/lib/evm_database_ops_spec.rb | 8 +-
 2 files changed, 15 insertions(+), 9 deletions(-)

[----] I, [2019-06-13T08:10:11.420028 #12868:1244f54]  INFO -- : MIQ(MiqQueue#deliver) Message id: [1000000001773], Delivering...
[----] I, [2019-06-13T08:10:11.421092 #12868:1244f54]  INFO -- : MIQ(MiqTask#update_status) Task: [1000000000030] [Active] [Ok] [Task starting]
[----] I, [2019-06-13T08:10:11.437198 #12868:1244f54]  INFO -- : MIQ(MiqTask#update_status) Task: [1000000000030] [Active] [Ok] [Starting DB Backup for Region: region_1]
[----] I, [2019-06-13T08:10:11.611254 #12868:1244f54]  INFO -- : MIQ(MiqNfsSession-mount_share) Connecting to host: [10.8.196.195], share: [/srv/export/db_backup/] using mount point: [/tmp/miq_20190613-12868-x2q5u3]...
[----] I, [2019-06-13T08:10:11.764415 #12868:1244f54]  INFO -- : MIQ(Class-disconnect) Disconnecting mount point: /tmp/miq_20190613-12868-x2q5u3
[----] I, [2019-06-13T08:10:11.784265 #12868:1244f54]  INFO -- : MIQ(Class-disconnect) Disconnecting mount point: /tmp/miq_20190613-12868-x2q5u3...Complete
[----] E, [2019-06-13T08:10:11.785510 #12868:1244f54] ERROR -- : MIQ(MiqQueue#deliver) Message id: [1000000001773], Error: [undefined method `path' for nil:NilClass]
[----] E, [2019-06-13T08:10:11.785687 #12868:1244f54] ERROR -- : [NoMethodError]: undefined method `path' for nil:NilClass  Method:[block (2 levels) in <class:LogProxy>]
[----] E, [2019-06-13T08:10:11.785817 #12868:1244f54] ERROR -- : /opt/rh/cfme-gemset/bundler/gems/cfme-gems-pending-98680009fe14/lib/gems/pending/util/mount/miq_generic_mount_session.rb:493:in `source_for_log'
/opt/rh/cfme-gemset/bundler/gems/cfme-gems-pending-98680009fe14/lib/gems/pending/util/mount/miq_generic_mount_session.rb:265:in `rescue in add'
/opt/rh/cfme-gemset/bundler/gems/cfme-gems-pending-98680009fe14/lib/gems/pending/util/mount/miq_generic_mount_session.rb:270:in `add'
/var/www/miq/vmdb/lib/evm_database_ops.rb:160:in `block in with_file_storage'
/opt/rh/cfme-gemset/bundler/gems/cfme-gems-pending-98680009fe14/lib/gems/pending/util/miq_file_storage.rb:31:in `with_interface_class'
/var/www/miq/vmdb/lib/evm_database_ops.rb:133:in `with_file_storage'
/var/www/miq/vmdb/lib/evm_database_ops.rb:57:in `backup'
/var/www/miq/vmdb/app/models/database_backup.rb:53:in `_backup'
/var/www/miq/vmdb/app/models/database_backup.rb:37:in `backup'
/var/www/miq/vmdb/app/models/database_backup.rb:14:in `backup'
/var/www/miq/vmdb/app/models/miq_queue.rb:455:in `block in dispatch_method'
/usr/share/ruby/timeout.rb:93:in `block in timeout'
/usr/share/ruby/timeout.rb:33:in `block in catch'
/usr/share/ruby/timeout.rb:33:in `catch'
/usr/share/ruby/timeout.rb:33:in `catch'
/usr/share/ruby/timeout.rb:108:in `timeout'
/var/www/miq/vmdb/app/models/miq_queue.rb:453:in `dispatch_method'
/var/www/miq/vmdb/app/models/miq_queue.rb:430:in `block in deliver'
/var/www/miq/vmdb/app/models/user.rb:275:in `with_user_group'
/var/www/miq/vmdb/app/models/miq_queue.rb:430:in `deliver'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:104:in `deliver_queue_message'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:137:in `deliver_message'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:155:in `block in do_work'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:149:in `loop'
/var/www/miq/vmdb/app/models/miq_queue_worker_base/runner.rb:149:in `do_work'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:329:in `block in do_work_loop'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:326:in `loop'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:326:in `do_work_loop'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:153:in `run'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:127:in `start'
/var/www/miq/vmdb/app/models/miq_worker/runner.rb:22:in `start_worker'
/var/www/miq/vmdb/app/models/miq_worker.rb:408:in `block in start_runner_via_fork'
/opt/rh/cfme-gemset/gems/nakayoshi_fork-0.0.4/lib/nakayoshi_fork.rb:23:in `fork'
/opt/rh/cfme-gemset/gems/nakayoshi_fork-0.0.4/lib/nakayoshi_fork.rb:23:in `fork'
/var/www/miq/vmdb/app/models/miq_worker.rb:406:in `start_runner_via_fork'
/var/www/miq/vmdb/app/models/miq_worker.rb:396:in `start_runner'
/var/www/miq/vmdb/app/models/miq_worker.rb:447:in `start'
/var/www/miq/vmdb/app/models/miq_worker.rb:277:in `start_worker'
/var/www/miq/vmdb/app/models/miq_worker.rb:154:in `block in sync_workers'
/var/www/miq/vmdb/app/models/miq_worker.rb:154:in `times'
/var/www/miq/vmdb/app/models/miq_worker.rb:154:in `sync_workers'
/var/www/miq/vmdb/app/models/miq_server/worker_management/monitor.rb:53:in `block in sync_workers'
/var/www/miq/vmdb/app/models/miq_server/worker_management/monitor.rb:50:in `each'
/var/www/miq/vmdb/app/models/miq_server/worker_management/monitor.rb:50:in `sync_workers'
/var/www/miq/vmdb/app/models/miq_server.rb:148:in `start'
/var/www/miq/vmdb/app/models/miq_server.rb:240:in `start'
/var/www/miq/vmdb/lib/workers/evm_server.rb:27:in `start'
/var/www/miq/vmdb/lib/workers/evm_server.rb:48:in `start'
/var/www/miq/vmdb/lib/workers/bin/evm_server.rb:4:in `<main>'
[----] I, [2019-06-13T08:10:11.785952 #12868:1244f54]  INFO -- : MIQ(MiqQueue#delivered) Message id: [1000000001773], State: [error], Delivered in [0.365913405] seconds
[----] I, [2019-06-13T08:10:11.787934 #12868:1244f54]  INFO -- : MIQ(MiqQueue#m_callback) Message id: [1000000001773], Invoking Callback with args: ["Finished", "error", "undefined method `path' for nil:NilClass", "nil"]
[----] I, [2019-06-13T08:10:11.788074 #12868:1244f54]  INFO -- : MIQ(MiqTask#update_status) Task: [1000000000030] [Finished] [Error] [undefined method `path' for nil:NilClass]
[----] I, [2019-06-13T08:10:14.089231 #13233:1244f54]  INFO -- : MIQ(ManageIQ::Providers::Vmware::InfraManager::EventCatcher::Runner#filtered?) EMS [env-nvc67-vcsa.cfme2.lab.eng.rdu2.redhat.com] as [administrator] Skipping caught event [UserLoginSessionEvent] chainId [2536443]

Worked with Jaroslav to debug this, and I am pretty sure that this is a issue with an invalid nfs path being passed in, meaning this is "technically" a user error and should still be working okay given a proper NFS endpoint (I hope...) without a code change required.


* * *


That said, we probably both agree that there are some other issues at hand here that should be addressed, but in separate tickets:

1. The above error is a known issue that masks the true error, and should be resolved.  Effectively a variable is being accessed in a `rescue` clause that is assumed to be set, but is not, causing a secondary error to be thrown, masking the original.  This should be safe guarded against so errors can be better propagated.
2. Even with this, errors probably won't get passed up to the UI, which is really where that should exist for something like this, and shouldn't have to be shown in the logs.


Again, both of these are separate issues to the original complaint and not addressed as part of this fix, but should really be addressed in other tickets.

Right now I cannot test this better than check whether the basic functionality still works.

I have found the file on nfs after the schedule should have triggered
/net/X.X.X.X/srv/export/db_backup/region_0/test/region_0_20190614_132510.backup: gzip compressed data, from Unix, original size 78149120

Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2019:1644

RHCFQE-14590


https://github.com/ManageIQ/integration_tests/pull/10318/files