Bug 1726313

Summary: When trying to assign a tag to a VM you are logged out of Cloudforms
Product: Red Hat CloudForms Management Engine Reporter: Ryan Spagnola <rspagnol>
Component: UI - OPSAssignee: Robin Knaur <rknaur>
Status: CLOSED ERRATA QA Contact: Angelina Vasileva <anikifor>
Severity: high Docs Contact: Red Hat CloudForms Documentation <cloudforms-docs>
Priority: medium    
Version: 5.10.5CC: abellott, anikifor, bmidwood, hkataria, jrafanie, lavenel, mfeifer, mpovolny, nansari, obarenbo, rknaur, saali, simaishi
Target Milestone: GAKeywords: ZStream
Target Release: 5.10.8   
Hardware: All   
OS: All   
Whiteboard:
Fixed In Version: 5.10.8.0 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2019-08-13 08:35:35 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: Bug
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: CFME Core Target Upstream Version:
Embargoed:

Description Ryan Spagnola 2019-07-02 15:16:21 UTC
Description of problem:
While trying to apply a tag, the session to CloudForms is lost. This only happens with tag categories that have a large number of values. The tag category has over 1000  values.

Version-Release number of selected component (if applicable):
5.10.5

How reproducible:
Always with large number of values

Steps to Reproduce:
1. Try to assign a tag from a category with a large number of values
2.
3.

Actual results:
appliance crashes

Expected results:
tag is assigned correctly

Additional info:
[----] I, [2019-06-26T13:54:30.657711 #2423:6d6f50]  INFO -- : MIQ(Vmdb::Loggers.apply_config) Log level for azure.log has been changed to [WARN]
[----] I, [2019-06-26T13:54:30.657892 #2423:6d6f50]  INFO -- : MIQ(Vmdb::Loggers.apply_config) Log level for vim.log has been changed to [WARN]
[----] I, [2019-06-26T13:54:31.015803 #2423:6d6f50]  INFO -- : MIQ(SessionStore) Using session_store: ActionDispatch::Session::MemCacheStore
[----] I, [2019-06-26T13:54:31.208495 #5250:946f4c]  INFO -- : MIQ(MiqServer#monitor_loop) Received SIGTERM signal, shutting down server
[----] I, [2019-06-26T13:54:31.208738 #5250:946f4c]  INFO -- : MIQ(MiqServer#shutdown) initiated for MiqServer [Census UI Portal] with ID: [777000000000016], PID: [5250], GUID: [e5f16b5c-f901-11e6-9607-0050568506a8]
[----] I, [2019-06-26T13:54:32.837035 #12138:946f4c]  INFO -- : MIQ(MiqScheduleWorker::Runner#do_work) Number of scheduled items to be processed: 0.
[----] I, [2019-06-26T13:54:47.838964 #12138:946f4c]  INFO -- : MIQ(MiqScheduleWorker::Runner#do_work) Number of scheduled items to be processed: 1.
[----] E, [2019-06-26T13:56:01.595217 #12138:946f4c] ERROR -- : MIQ(MiqScheduleWorker::Runner#do_work) SIGTERM
[----] E, [2019-06-26T13:56:01.595473 #12138:946f4c] ERROR -- : [SignalException]: SIGTERM  Method:[block (2 levels) in <class:LogProxy>]
[----] E, [2019-06-26T13:56:01.595589 #12138:946f4c] ERROR -- : /opt/rh/cfme-gemset/gems/activerecord-5.0.7.2/lib/active_record/connection_adapters/postgresql_adapter.rb:600:in `async_exec'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.2/lib/active_record/connection_adapters/postgresql_adapter.rb:600:in `block in exec_no_cache'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.2/lib/active_record/connection_adapters/abstract_adapter.rb:590:in `block in log'
/opt/rh/cfme-gemset/gems/activesupport-5.0.7.2/lib/active_support/notifications/instrumenter.rb:21:in `instrument'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.2/lib/active_record/connection_adapters/abstract_adapter.rb:583:in `log'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.2/lib/active_record/connection_adapters/postgresql_adapter.rb:600:in `exec_no_cache'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.2/lib/active_record/connection_adapters/postgresql_adapter.rb:589:in `execute_and_clear'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.2/lib/active_record/connection_adapters/postgresql/database_statements.rb:103:in `exec_query'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.2/lib/active_record/connection_adapters/abstract/database_statements.rb:373:in `select'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.2/lib/active_record/connection_adapters/abstract/database_statements.rb:41:in `select_all'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.2/lib/active_record/connection_adapters/abstract/query_cache.rb:95:in `select_all'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.2/lib/active_record/querying.rb:39:in `find_by_sql'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.2/lib/active_record/relation.rb:706:in `exec_queries'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.2/lib/active_record/relation.rb:583:in `load'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.2/lib/active_record/relation.rb:260:in `records'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.2/lib/active_record/relation.rb:256:in `to_a'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.2/lib/active_record/relation/finder_methods.rb:563:in `find_nth_with_limit'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.2/lib/active_record/relation/finder_methods.rb:592:in `find_nth_with_limit_and_offset'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.2/lib/active_record/relation/finder_methods.rb:545:in `find_nth'
/opt/rh/cfme-gemset/gems/activerecord-5.0.7.2/lib/active_record/relation/finder_methods.rb:122:in `first'
/var/www/miq/vmdb/app/models/miq_queue.rb:343:in `block in put_or_update'
/var/www/miq/vmdb/app/models/miq_queue.rb:342:in `loop'
/var/www/miq/vmdb/app/models/miq_queue.rb:342:in `put_or_update'
/var/www/miq/vmdb/app/models/miq_queue.rb:386:in `put_unless_exists'
/var/www/miq/vmdb/app/models/miq_schedule_worker/jobs.rb:199:in `queue_work'
/var/www/miq/vmdb/app/models/miq_schedule_worker/jobs.rb:11:in `miq_server_status_update'
/var/www/miq/vmdb/app/models/miq_schedule_worker/runner.rb:532:in `public_send'
/var/www/miq/vmdb/app/models/miq_schedule_worker/runner.rb:532: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>'
- Gracefully stopping, waiting for requests to finish
=== puma shutdown: 2019-06-26 13:56:01 -0400 ===
- Goodbye!
Exiting
- Gracefully stopping, waiting for requests to finish
- Gracefully stopping, waiting for requests to finish
=== puma shutdown: 2019-06-26 13:56:01 -0400 ===
- Goodbye!
=== puma shutdown: 2019-06-26 13:56:01 -0400 ===Exiting

- Goodbye!
Exiting
- Gracefully stopping, waiting for requests to finish
=== puma shutdown: 2019-06-26 13:56:01 -0400 ===
- Goodbye!
Exiting
- Gracefully stopping, waiting for requests to finish
=== puma shutdown: 2019-06-26 13:56:01 -0400 ===
- Goodbye!
Exiting
- Gracefully stopping, waiting for requests to finish
=== puma shutdown: 2019-06-26 13:56:01 -0400 ===
- Goodbye!
Exiting
- Gracefully stopping, waiting for requests to finish
=== puma shutdown: 2019-06-26 13:56:01 -0400 ===
- Goodbye!
Exiting
- Gracefully stopping, waiting for requests to finish
=== puma shutdown: 2019-06-26 13:56:01 -0400 ===
- Goodbye!
Exiting
- Gracefully stopping, waiting for requests to finish
=== puma shutdown: 2019-06-26 13:56:01 -0400 ===
- Goodbye!
Exiting
- Gracefully stopping, waiting for requests to finish
=== puma shutdown: 2019-06-26 13:56:01 -0400 ===
- Goodbye!
Exiting
Wed Jun 26 17:56:28 UTC 2019 EVMINIT   EVM Appliance Booted
removed ‘/var/www/miq/vmdb/tmp/pids/evm.pid’

Comment 16 Angelina Vasileva 2019-08-05 08:30:19 UTC
Fixed and verified in 5.10.8.0.20190729222758_e725e22 with a category with 10000 values.

Verification steps:
1. SSH to the appliance

# vmdb
# bin/rails c
Loading production environment (Rails 5.0.7.2)
irb(main):001:0> 10000.times { |i| Classification.first.add_entry(:name => i.to_s, :description => i.to_s)}
PostgreSQLAdapter#log_after_checkout, connection_pool: size: 5, connections: 1, in use: 1, waiting_in_queue: 0
=> 10000
irb(main):002:0> Classification.first
=> #<Classification id: 1, description: "Location", icon: nil, read_only: false, syntax: "string", single_value: true, example_text: "The geographic location of the resource, such as N...", tag_id: 3, parent_id: 0, show: true, default: true, perf_by_tag: nil>


2. In the UI, navigate to VMs and assign a tag from Location category to any VM. 
3. Verify the tag is assigned.
4. The user is not logged out.

Comment 18 errata-xmlrpc 2019-08-13 08:35:35 UTC
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/RHSA-2019:2466