Skip to content

Instantly share code, notes, and snippets.

@kbrock
Created September 4, 2015 15:40
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save kbrock/fe49f79be9c88fb0ac9b to your computer and use it in GitHub Desktop.
Save kbrock/fe49f79be9c88fb0ac9b to your computer and use it in GitHub Desktop.
evm.log with pruned timestamp to reduce width
# Logfile created on 2015-09-04 10:56:03 -0400 by logger.rb/47272
[-] I 10:56:03.728893 #13407] : MIQ(Vmdb::Loggers.apply_config) Log level for vim.log has been changed to [WARN]
[-] I 10:56:05.020030 #13407] : MIQ(Vmdb::Initializer.init) - Program Name: /Users/kbrock/.gem/ruby/2.2.2/bin/rake, PID: 13407, ENV['MIQ_GUID']: , ENV['EVMSERVER']:
[-] I 10:56:05.024106 #13407] : MIQ(Vmdb::Initializer.init) - Init complete
[-] I 10:56:05.711462 #13407] : MIQ(EvmApplication.start) EVM Startup initiated
[-] I 10:56:10.646710 #13413] : MIQ(Vmdb::Loggers.apply_config) Log level for vim.log has been changed to [WARN]
** EVM vmdb_development ** 1
[-] I 10:56:11.568937 #13413] : MIQ(Vmdb::Initializer.init) - Program Name: /Users/kbrock/src/manageiq/bin/rails, PID: 13413, ENV['MIQ_GUID']: , ENV['EVMSERVER']:
[-] I 10:56:11.572899 #13413] : MIQ(Vmdb::Initializer.init) - Init complete
[-] I 10:56:12.233358 #13413] : MIQ(MiqServer.validate_database) Database Adapter: [PostgreSQL], version: [PostgreSQL 9.2.8 on x86_64-apple-darwin14.1.0, compiled by Apple LLVM version 6.0 (clang-600.0.56) (based on LLVM 3.5svn), 64-bit]
[-] I 10:56:12.234558 #13413] : MIQ(EvmDatabase.seed) Seeding...
[-] I 10:56:12.244435 #13413] : MIQ(EvmDatabase.seed) Seeding MiqDatabase
[-] I 10:56:12.311534 #13413] : MIQ(EvmDatabase.seed) Seeding MiqRegion
[-] I 10:56:12.324255 #13413] : MIQ(EvmDatabase.seed) Seeding MiqEnterprise
[-] I 10:56:12.343897 #13413] : MIQ(EvmDatabase.seed) Seeding Zone
[-] I 10:56:12.349425 #13413] : MIQ(EvmDatabase.seed) Seeding MiqServer
[-] I 10:56:12.374174 #13413] : MIQ(EvmDatabase.seed) Seeding ServerRole
[-] I 10:56:12.410428 #13413] : MIQ(EvmDatabase.seed) Seeding Tenant
[-] I 10:56:12.426400 #13413] : MIQ(EvmDatabase.seed) Seeding MiqProductFeature
[-] I 10:56:12.569223 #13413] : MIQ(MiqProductFeature.seed_from_hash) Updating product feature: Identifier: [ab_group_new], Name: [Add a new Button Group]
[-] I 10:56:12.576335 #13413] : MIQ(MiqProductFeature.seed_from_hash) Updating product feature: Identifier: [ab_group_edit], Name: [Edit Button Group]
[-] I 10:56:12.578631 #13413] : MIQ(MiqProductFeature.seed_from_hash) Updating product feature: Identifier: [ab_group_delete], Name: [Remove Button Group]
[-] I 10:56:12.582074 #13413] : MIQ(MiqProductFeature.seed_from_hash) Updating product feature: Identifier: [ab_button_new], Name: [Add a new Button]
[-] I 10:56:12.585276 #13413] : MIQ(MiqProductFeature.seed_from_hash) Updating product feature: Identifier: [ab_button_delete], Name: [Remove Button]
[-] I 10:56:12.587597 #13413] : MIQ(MiqProductFeature.seed_from_hash) Updating product feature: Identifier: [ab_group_reorder], Name: [Reorder Buttons and Groups]
[-] I 10:56:12.805595 #13413] : MIQ(MiqProductFeature.seed_from_hash) Updating product feature: Identifier: [ab_group_new], Name: [Add Button Group]
[-] I 10:56:12.807969 #13413] : MIQ(MiqProductFeature.seed_from_hash) Updating product feature: Identifier: [ab_button_new], Name: [Add Button]
[-] I 10:56:12.810201 #13413] : MIQ(MiqProductFeature.seed_from_hash) Updating product feature: Identifier: [ab_group_edit], Name: [Edit]
[-] I 10:56:12.814836 #13413] : MIQ(MiqProductFeature.seed_from_hash) Updating product feature: Identifier: [ab_group_delete], Name: [Delete]
[-] I 10:56:12.817803 #13413] : MIQ(MiqProductFeature.seed_from_hash) Updating product feature: Identifier: [ab_group_reorder], Name: [Reorder]
[-] I 10:56:12.821605 #13413] : MIQ(MiqProductFeature.seed_from_hash) Updating product feature: Identifier: [ab_button_new], Name: [Add Button]
[-] I 10:56:12.824526 #13413] : MIQ(MiqProductFeature.seed_from_hash) Updating product feature: Identifier: [ab_group_edit], Name: [Edit]
[-] I 10:56:12.826896 #13413] : MIQ(MiqProductFeature.seed_from_hash) Updating product feature: Identifier: [ab_button_delete], Name: [Delete]
[-] I 10:56:13.066492 #13413] : MIQ(EvmDatabase.seed) Seeding MiqUserRole
[-] I 10:56:13.221688 #13413] : MIQ(EvmDatabase.seed) Seeding MiqGroup
[-] I 10:56:13.255968 #13413] : MIQ(EvmDatabase.seed) Seeding User
[-] I 10:56:13.329348 #13413] : MIQ(EvmDatabase.seed) Seeding MiqReport
[-] I 10:56:13.604644 #13413] : MIQ(EvmDatabase.seed) Seeding RssFeed
[-] I 10:56:13.693254 #13413] : MIQ(EvmDatabase.seed) Seeding MiqWidget
[-] I 10:56:13.793319 #13413] : Widget Set: [Default Dashboard] file has been updated on disk, synchronizing with model
[-] I 10:56:13.826948 #13413] : MIQ(EvmDatabase.seed) Seeding VmdbDatabase
** EVM vmdb_development ** 2
** EVM vmdb_development ** 3
** EVM vmdb_development ** 4
[-] I 10:56:15.328716 #13413] : MIQ(EvmDatabase.seed) Seeding... Complete
[-] W 10:56:15.348747 #13413] : MIQ(MiqServer.activate_configuration) database schema is from a newer version of the product and may be incompatible. Schema version is [20150903162623]. Missing files: [20150710175014, 20150903162623]
[-] W 10:56:15.348780 #13413] : MIQ(MiqServer.activate_configuration) appliance should be updated to match database version
[-] I 10:56:15.571006 #13413] : MIQ(Configuration.create_or_update) Created server configuration in db: id: [1], typ: [vmdb], miq_server_id: [3]
[-] I 10:56:15.586974 #13413] : MIQ(VMDB::Config#save) Saved Config [vmdb] from database in file: [/Users/kbrock/src/manageiq/config/vmdb.yml.db]
[-] I 10:56:15.647541 #13413] : MIQ(MiqQueue.put) Message id: [2], id: [], Zone: [default], Role: [], Server: [c69aab4c-4755-11e5-8436-b8e856479e14], Ident: [generic], Target id: [], Instance id: [3], Task id: [], Command: [MiqServer.ntp_reload], Timeout: [600], Priority: [20], State: [ready], Deliver On: [], Data: [], Args: [{:server=>["0.pool.ntp.org", "1.pool.ntp.org", "2.pool.ntp.org"]}]
[-] I 10:56:15.807880 #13413] : MIQ(Configuration.create_or_update) Updated server configuration: id: [1], typ: [vmdb], miq_server_id: [3]
[-] I 10:56:15.822266 #13413] : MIQ(VMDB::Config#save) Saved Config [vmdb] from database in file: [/Users/kbrock/src/manageiq/config/vmdb.yml.db]
[-] I 10:56:15.829055 #13413] : MIQ(MiqServer#ntp_reload_queue) Previous ntp_reload is still running, skipping...Resource: [MiqServer], id: [3]
[-] I 10:56:15.835608 #13413] : MIQ(MiqQueue.put_or_update) Message id: [2] updated with following: {:queue_name=>"generic", :state=>"ready", :zone=>"default", :class_name=>"MiqServer", :instance_id=>3, :method_name=>"ntp_reload", :server_guid=>"c69aab4c-4755-11e5-8436-b8e856479e14", :priority=>20, :args=>[{:server=>["0.pool.ntp.org", "1.pool.ntp.org", "2.pool.ntp.org"]}]}
[-] I 10:56:15.835688 #13413] : MIQ(MiqQueue.put_or_update) Message id: [2], id: [], Zone: [default], Role: [], Server: [c69aab4c-4755-11e5-8436-b8e856479e14], Ident: [generic], Target id: [], Instance id: [3], Task id: [], Command: [MiqServer.ntp_reload], Timeout: [600], Priority: [20], State: [ready], Deliver On: [], Data: [], Args: [{:server=>["0.pool.ntp.org", "1.pool.ntp.org", "2.pool.ntp.org"]}], Requeued
[-] I 10:56:17.235821 #13413] : MIQ(MiqServer.start) Server IP Address: 10.193.20.40
[-] I 10:56:17.235859 #13413] : MIQ(MiqServer.start) Server Hostname: kbrock-redhat.local
[-] I 10:56:17.235892 #13413] : MIQ(MiqServer.start) Server MAC Address: b8:e8:56:47:9e:14
[-] I 10:56:17.235921 #13413] : MIQ(MiqServer.start) Server GUID: c69aab4c-4755-11e5-8436-b8e856479e14
[-] I 10:56:17.237647 #13413] : MIQ(MiqServer.start) Server Zone: default
[-] I 10:56:17.244943 #13413] : MIQ(MiqServer.start) Server Role:
[-] I 10:56:17.245940 #13413] : MIQ(MiqServer.start) Server Region number: 0, name: Region 0
[-] I 10:56:17.247520 #13413] : MIQ(MiqServer.start) Database Latency: 0.15115890018932987 ms
[-] I 10:56:17.248996 #13413] : *************************************************
[-] I 10:56:17.249031 #13413] : * [VMDB] started on [2015-09-04 10:56:17 -0400] *
[-] I 10:56:17.249046 #13413] : *************************************************
[-] I 10:56:17.249102 #13413] : Version: master
[-] I 10:56:17.255918 #13413] : Build: 20150904105617_ffa90f7
[-] I 10:56:17.256130 #13413] : RUBY Environment: ruby 2.2.2p95 (2015-04-13 revision 50295) [x86_64-darwin14]
[-] I 10:56:17.256175 #13413] : RAILS Environment: development version 4.2.3
[-] I 10:56:17.256194 #13413] : VMDB settings:
[-] I 10:56:17.278337 #13413] : :api:
[-] I 10:56:17.278406 #13413] : :token_ttl: 10.minutes
[-] I 10:56:17.278425 #13413] : :authentication_timeout: 30.seconds
[-] I 10:56:17.278441 #13413] : :authentication:
[-] I 10:56:17.278454 #13413] : :basedn:
[-] I 10:56:17.278493 #13413] : :bind_dn:
[-] I 10:56:17.278509 #13413] : :get_direct_groups: true
[-] I 10:56:17.278523 #13413] : :group_memberships_max_depth: 2
[-] I 10:56:17.278537 #13413] : :ldaphost:
[-] I 10:56:17.278587 #13413] : :ldapport: '389'
[-] I 10:56:17.278603 #13413] : :mode: database
[-] I 10:56:17.278618 #13413] : :user_suffix:
[-] I 10:56:17.278630 #13413] : :user_type: userprincipalname
[-] I 10:56:17.278642 #13413] : :amazon_key:
[-] I 10:56:17.278657 #13413] : :coresident_miqproxy:
[-] I 10:56:17.278670 #13413] : :concurrent_per_ems: 1
[-] I 10:56:17.278683 #13413] : :concurrent_per_host: 1
[-] I 10:56:17.278698 #13413] : :scan_via_host: true
[-] I 10:56:17.278728 #13413] : :use_vim_broker: true
[-] I 10:56:17.278741 #13413] : :database:
[-] I 10:56:17.278753 #13413] : :metrics_collection:
[-] I 10:56:17.278800 #13413] : :collection_schedule: 1 * * * *
[-] I 10:56:17.278814 #13413] : :daily_rollup_schedule: 23 0 * * *
[-] I 10:56:17.278826 #13413] : :metrics_history:
[-] I 10:56:17.278838 #13413] : :keep_daily_metrics: 6.months
[-] I 10:56:17.278849 #13413] : :keep_hourly_metrics: 6.months
[-] I 10:56:17.278862 #13413] : :purge_schedule: 50 * * * *
[-] I 10:56:17.278875 #13413] : :purge_window_size: 100000
[-] I 10:56:17.278886 #13413] : :ldap_synchronization:
[-] I 10:56:17.278899 #13413] : :ldap_synchronization_schedule: 0 2 * * *
[-] I 10:56:17.278910 #13413] : :drift_states:
[-] I 10:56:17.278941 #13413] : :history:
[-] I 10:56:17.278953 #13413] : :keep_drift_states: 6.months
[-] I 10:56:17.278964 #13413] : :purge_window_size: 10000
[-] I 10:56:17.278975 #13413] : :ems:
[-] I 10:56:17.278987 #13413] : :ems_redhat:
[-] I 10:56:17.279002 #13413] : :service:
[-] I 10:56:17.279041 #13413] : :read_timeout: 1.hour
[-] I 10:56:17.279054 #13413] : :ems_events:
[-] I 10:56:17.279066 #13413] : :history:
[-] I 10:56:17.279078 #13413] : :keep_ems_events: 6.months
[-] I 10:56:17.279091 #13413] : :purge_window_size: 1000
[-] I 10:56:17.279103 #13413] : :ems_refresh:
[-] I 10:56:17.279141 #13413] : :capture_vm_created_on_date: false
[-] I 10:56:17.279157 #13413] : :ec2:
[-] I 10:56:17.279169 #13413] : get_private_images: true
[-] I 10:56:17.279180 #13413] : get_shared_images: true
[-] I 10:56:17.279191 #13413] : get_public_images: false
[-] I 10:56:17.279204 #13413] : ignore_terminated_instances: true
[-] I 10:56:17.279217 #13413] : :foreman_configuration:
[-] I 10:56:17.279229 #13413] : :refresh_interval: 15.minutes
[-] I 10:56:17.279240 #13413] : :foreman_provisioning:
[-] I 10:56:17.279252 #13413] : :refresh_interval: 1.hour
[-] I 10:56:17.279284 #13413] : :full_refresh_threshold: 100
[-] I 10:56:17.279297 #13413] : :kubernetes:
[-] I 10:56:17.279309 #13413] : :refresh_interval: 15.minutes
[-] I 10:56:17.279320 #13413] : :openshift:
[-] I 10:56:17.279331 #13413] : :refresh_interval: 15.minutes
[-] I 10:56:17.279378 #13413] : :raise_vm_snapshot_complete_if_created_within: 15.minutes
[-] I 10:56:17.279398 #13413] : :refresh_interval: 24.hours
[-] I 10:56:17.279411 #13413] : :scvmm:
[-] I 10:56:17.279422 #13413] : :refresh_interval: 15.minutes
[-] I 10:56:17.279435 #13413] : :host_scan:
[-] I 10:56:17.279447 #13413] : :queue_timeout: 20.minutes
[-] I 10:56:17.279458 #13413] : :http_proxy:
[-] I 10:56:17.279469 #13413] : :host:
[-] I 10:56:17.279482 #13413] : :port:
[-] I 10:56:17.279493 #13413] : :user:
[-] I 10:56:17.279503 #13413] : :log:
[-] I 10:56:17.279516 #13413] : :collection:
[-] I 10:56:17.279527 #13413] : :archive:
[-] I 10:56:17.279589 #13413] : :pattern:
[-] I 10:56:17.279603 #13413] : :current:
[-] I 10:56:17.279614 #13413] : :pattern:
[-] I 10:56:17.279627 #13413] : - log/*.log
[-] I 10:56:17.279638 #13413] : - log/apache/*.log
[-] I 10:56:17.279649 #13413] : - log/*.txt
[-] I 10:56:17.279660 #13413] : - config/*
[-] I 10:56:17.279671 #13413] : - "/var/log/syslog*"
[-] I 10:56:17.279682 #13413] : - "/var/log/daemon.log*"
[-] I 10:56:17.279693 #13413] : - "/etc/default/ntp*"
[-] I 10:56:17.279704 #13413] : - "/var/log/messages*"
[-] I 10:56:17.279717 #13413] : - "/var/log/cron*"
[-] I 10:56:17.279751 #13413] : - BUILD
[-] I 10:56:17.279765 #13413] : - GUID
[-] I 10:56:17.279777 #13413] : - VERSION
[-] I 10:56:17.279789 #13413] : :ping_depot: true
[-] I 10:56:17.279801 #13413] : :ping_depot_timeout: 20
[-] I 10:56:17.279812 #13413] : :level: info
[-] I 10:56:17.279823 #13413] : :level_rails: info
[-] I 10:56:17.279834 #13413] : :level_aws: info
[-] I 10:56:17.279845 #13413] : :level_aws_in_evm: error
[-] I 10:56:17.279856 #13413] : :level_kube: info
[-] I 10:56:17.279898 #13413] : :level_kube_in_evm: error
[-] I 10:56:17.279912 #13413] : :level_api: info
[-] I 10:56:17.279925 #13413] : :level_api_in_evm: error
[-] I 10:56:17.279936 #13413] : :level_fog: info
[-] I 10:56:17.279947 #13413] : :level_fog_in_evm: error
[-] I 10:56:17.279959 #13413] : :level_rhevm: info
[-] I 10:56:17.279970 #13413] : :level_rhevm_in_evm: error
[-] I 10:56:17.279981 #13413] : :level_scvmm: info
[-] I 10:56:17.279995 #13413] : :level_scvmm_in_evm: error
[-] I 10:56:17.280006 #13413] : :level_vim: warn
[-] I 10:56:17.280018 #13413] : :level_vim_in_evm: error
[-] I 10:56:17.280063 #13413] : :path:
[-] I 10:56:17.280077 #13413] : :log_depot:
[-] I 10:56:17.280089 #13413] : :uri:
[-] I 10:56:17.280102 #13413] : :username:
[-] I 10:56:17.280113 #13413] : :management_system:
[-] I 10:56:17.280124 #13413] : :power_operation_expiration: 10.minutes
[-] I 10:56:17.280135 #13413] : :performance:
[-] I 10:56:17.280146 #13413] : :capture_threshold:
[-] I 10:56:17.280203 #13413] : :ems_cluster: 50.minutes
[-] I 10:56:17.280215 #13413] : :host: 50.minutes
[-] I 10:56:17.280228 #13413] : :storage: 60.minutes
[-] I 10:56:17.280240 #13413] : :vm: 50.minutes
[-] I 10:56:17.280251 #13413] : :capture_threshold_with_alerts:
[-] I 10:56:17.280262 #13413] : :host: 20.minutes
[-] I 10:56:17.280273 #13413] : :vm: 20.minutes
[-] I 10:56:17.280286 #13413] : :concurrent_requests:
[-] I 10:56:17.280298 #13413] : :hourly: 1
[-] I 10:56:17.280326 #13413] : :realtime: 20
[-] I 10:56:17.280340 #13413] : :history:
[-] I 10:56:17.280353 #13413] : :initial_capture_days: 0
[-] I 10:56:17.280365 #13413] : :keep_daily_performances: 6.months
[-] I 10:56:17.280376 #13413] : :keep_hourly_performances: 6.months
[-] I 10:56:17.280387 #13413] : :keep_realtime_performances: 4.hours
[-] I 10:56:17.280436 #13413] : :purge_window_size: 1000
[-] I 10:56:17.280450 #13413] : :host_overhead:
[-] I 10:56:17.280462 #13413] : :memory: 2.01.percent
[-] I 10:56:17.280473 #13413] : :cpu: 0.15.percent
[-] I 10:56:17.280484 #13413] : :policy_events:
[-] I 10:56:17.280496 #13413] : :history:
[-] I 10:56:17.280509 #13413] : :keep_policy_events: 6.months
[-] I 10:56:17.280521 #13413] : :purge_window_size: 1000
[-] I 10:56:17.280566 #13413] : :product:
[-] I 10:56:17.280579 #13413] : :maindb: ExtManagementSystem
[-] I 10:56:17.280591 #13413] : :reporting:
[-] I 10:56:17.280601 #13413] : :format_by_class:
[-] I 10:56:17.280615 #13413] : :Fixnum:
[-] I 10:56:17.280626 #13413] : :function:
[-] I 10:56:17.280638 #13413] : :name: number_with_delimiter
[-] I 10:56:17.280684 #13413] : :Float:
[-] I 10:56:17.280698 #13413] : :function:
[-] I 10:56:17.280711 #13413] : :name: number_with_delimiter
[-] I 10:56:17.280723 #13413] : :format_by_column: {}
[-] I 10:56:17.280735 #13413] : :history:
[-] I 10:56:17.280752 #13413] : :keep_reports: 6.months
[-] I 10:56:17.280766 #13413] : :purge_window_size: 100
[-] I 10:56:17.280777 #13413] : :precision:
[-] I 10:56:17.280788 #13413] : :default: 2
[-] I 10:56:17.280802 #13413] : :precision_by_column:
[-] I 10:56:17.280829 #13413] : :slope: 4
[-] I 10:56:17.280840 #13413] : :queue_timeout: 1.hour
[-] I 10:56:17.280851 #13413] : :repository_scanning:
[-] I 10:56:17.280863 #13413] : :defaultsmartproxy:
[-] I 10:56:17.280874 #13413] : :server:
[-] I 10:56:17.280916 #13413] : :case_sensitive_name_search: false
[-] I 10:56:17.280928 #13413] : :company: My Company
[-] I 10:56:17.280939 #13413] : :custom_logo: false
[-] I 10:56:17.280950 #13413] : :events:
[-] I 10:56:17.280964 #13413] : :disk_usage_gt_percent: 80
[-] I 10:56:17.280976 #13413] : :host: 10.193.20.40
[-] I 10:56:17.280987 #13413] : :listening_port: '443'
[-] I 10:56:17.280998 #13413] : :mks_classid: 338095E4-1806-4BA3-AB51-38A3179200E9
[-] I 10:56:17.281050 #13413] : :mks_version: 2.1.0.0
[-] I 10:56:17.281064 #13413] : :monitor_poll: 5.seconds
[-] I 10:56:17.281075 #13413] : :name: EVM
[-] I 10:56:17.281086 #13413] : :rails_server: thin
[-] I 10:56:17.281097 #13413] : :remote_console_type: VMRC
[-] I 10:56:17.281109 #13413] : :role: database_operations,event,reporting,scheduler,smartstate,ems_operations,ems_inventory,user_interface,web_services,automate
[-] I 10:56:17.281121 #13413] : :server_dequeue_frequency: 5.seconds
[-] I 10:56:17.281132 #13413] : :session_store: cache
[-] I 10:56:17.281182 #13413] : :startup_timeout: 300
[-] I 10:56:17.281194 #13413] : :timezone: UTC
[-] I 10:56:17.281206 #13413] : :worker_monitor:
[-] I 10:56:17.281217 #13413] : :kill_algorithm:
[-] I 10:56:17.281228 #13413] : :name: :used_swap_percent_gt_value
[-] I 10:56:17.281239 #13413] : :value: 80
[-] I 10:56:17.281250 #13413] : :miq_server_time_threshold: 2.minutes
[-] I 10:56:17.281263 #13413] : :nice_delta: 1
[-] I 10:56:17.281275 #13413] : :poll: 2.seconds
[-] I 10:56:17.281286 #13413] : :start_algorithm:
[-] I 10:56:17.281297 #13413] : :name: :used_swap_percent_lt_value
[-] I 10:56:17.281308 #13413] : :value: 60
[-] I 10:56:17.281359 #13413] : :sync_interval: 30.minutes
[-] I 10:56:17.281372 #13413] : :wait_for_started_timeout: 10.minutes
[-] I 10:56:17.281383 #13413] : :zone: default
[-] I 10:56:17.281400 #13413] : :hostname: kbrock-redhat.local
[-] I 10:56:17.281413 #13413] : :session:
[-] I 10:56:17.281425 #13413] : :interval: 60
[-] I 10:56:17.281438 #13413] : :memcache_server: 127.0.0.1:11211
[-] I 10:56:17.281450 #13413] : :memcache_server_opts: "-l 127.0.0.1"
[-] I 10:56:17.281462 #13413] : :show_login_info: true
[-] I 10:56:17.281504 #13413] : :timeout: 3600
[-] I 10:56:17.281516 #13413] : :smartproxy_deploy:
[-] I 10:56:17.281528 #13413] : :queue_timeout: 30.minutes
[-] I 10:56:17.281539 #13413] : :smtp:
[-] I 10:56:17.281552 #13413] : :authentication: login
[-] I 10:56:17.281564 #13413] : :domain: mydomain.com
[-] I 10:56:17.281576 #13413] : :from: cfadmin@cfserver.com
[-] I 10:56:17.281587 #13413] : :host: localhost
[-] I 10:56:17.281625 #13413] : :port: '25'
[-] I 10:56:17.281639 #13413] : :user_name: evmadmin
[-] I 10:56:17.281651 #13413] : :snapshots:
[-] I 10:56:17.281662 #13413] : :create_free_percent: 100
[-] I 10:56:17.281674 #13413] : :remove_free_percent: 100
[-] I 10:56:17.281685 #13413] : :storage:
[-] I 10:56:17.281696 #13413] : :inventory:
[-] I 10:56:17.281707 #13413] : :full_refresh_schedule: 38 * * * *
[-] I 10:56:17.281719 #13413] : :metrics_collection:
[-] I 10:56:17.281731 #13413] : :collection_schedule: 0,15,30,45 * * * *
[-] I 10:56:17.281802 #13413] : :hourly_rollup_schedule: 8 * * * *
[-] I 10:56:17.281814 #13413] : :daily_rollup_schedule: 23 0 * * *
[-] I 10:56:17.281826 #13413] : :collection_interval: 15.minutes
[-] I 10:56:17.281837 #13413] : :max_gap_to_fill: 6.hours
[-] I 10:56:17.281848 #13413] : :metrics_history:
[-] I 10:56:17.281860 #13413] : :purge_schedule: 50 * * * *
[-] I 10:56:17.281871 #13413] : :keep_daily_metrics: 6.months
[-] I 10:56:17.281882 #13413] : :keep_hourly_metrics: 6.months
[-] I 10:56:17.281893 #13413] : :keep_realtime_metrics: 4.hours
[-] I 10:56:17.281905 #13413] : :purge_window_size: 1000
[-] I 10:56:17.281948 #13413] : :webservices:
[-] I 10:56:17.281961 #13413] : :consume_protocol: https
[-] I 10:56:17.281973 #13413] : :contactwith: ipaddress
[-] I 10:56:17.281984 #13413] : :integrate:
[-] I 10:56:17.281997 #13413] : :security: basic
[-] I 10:56:17.282008 #13413] : :mode: invoke
[-] I 10:56:17.282020 #13413] : :nameresolution: false
[-] I 10:56:17.282033 #13413] : :provide_protocol: https
[-] I 10:56:17.282050 #13413] : :security: none
[-] I 10:56:17.282064 #13413] : :timeout: 120
[-] I 10:56:17.282130 #13413] : :use_vim_broker: true
[-] I 10:56:17.282143 #13413] : :authentication_timeout: 30.seconds
[-] I 10:56:17.282156 #13413] : :workers:
[-] I 10:56:17.282168 #13413] : :worker_base:
[-] I 10:56:17.282180 #13413] : :defaults:
[-] I 10:56:17.282192 #13413] : :count: 1
[-] I 10:56:17.282204 #13413] : :gc_interval: 15.minutes
[-] I 10:56:17.282216 #13413] : :heartbeat_freq: 60.seconds
[-] I 10:56:17.282227 #13413] : :heartbeat_timeout: 2.minutes
[-] I 10:56:17.282238 #13413] : :memory_threshold: 200.megabytes
[-] I 10:56:17.282249 #13413] : :nice_delta: 10
[-] I 10:56:17.282260 #13413] : :parent_time_threshold: 3.minutes
[-] I 10:56:17.282273 #13413] : :poll: 3.seconds
[-] I 10:56:17.282286 #13413] : :poll_escalate_max: 30.seconds
[-] I 10:56:17.282318 #13413] : :poll_method: :normal
[-] I 10:56:17.282330 #13413] : :restart_interval: 0.hours
[-] I 10:56:17.282342 #13413] : :starting_timeout: 10.minutes
[-] I 10:56:17.282353 #13413] : :ems_refresh_core_worker:
[-] I 10:56:17.282364 #13413] : :poll: 1.seconds
[-] I 10:56:17.282377 #13413] : :memory_threshold: 400.megabytes
[-] I 10:56:17.282389 #13413] : :nice_delta: 1
[-] I 10:56:17.282444 #13413] : :thread_shutdown_timeout: 10.seconds
[-] I 10:56:17.282459 #13413] : :event_catcher:
[-] I 10:56:17.282471 #13413] : :defaults:
[-] I 10:56:17.282485 #13413] : :ems_event_page_size: 100
[-] I 10:56:17.282497 #13413] : :ems_event_thread_shutdown_timeout: 10.seconds
[-] I 10:56:17.282509 #13413] : :memory_threshold: 2.gigabytes
[-] I 10:56:17.282544 #13413] : :nice_delta: 1
[-] I 10:56:17.282556 #13413] : :poll: 1.seconds
[-] I 10:56:17.282567 #13413] : :event_catcher_redhat:
[-] I 10:56:17.282581 #13413] : :poll: 15.seconds
[-] I 10:56:17.282595 #13413] : :event_catcher_vmware:
[-] I 10:56:17.282606 #13413] : :poll: 1.seconds
[-] I 10:56:17.282617 #13413] : :event_catcher_openstack:
[-] I 10:56:17.282629 #13413] : :poll: 15.seconds
[-] I 10:56:17.282685 #13413] : :topics:
[-] I 10:56:17.282697 #13413] : :nova: notifications.*
[-] I 10:56:17.282709 #13413] : :cinder: notifications.*
[-] I 10:56:17.282721 #13413] : :glance: notifications.*
[-] I 10:56:17.282737 #13413] : :quantum: notifications.*
[-] I 10:56:17.282752 #13413] : :duration: 10.seconds
[-] I 10:56:17.282804 #13413] : :capacity: 50
[-] I 10:56:17.282819 #13413] : :amqp_port: 5672
[-] I 10:56:17.282834 #13413] : :event_catcher_openstack_infra:
[-] I 10:56:17.282847 #13413] : :poll: 15.seconds
[-] I 10:56:17.282860 #13413] : :topics:
[-] I 10:56:17.282871 #13413] : :nova: notifications.*
[-] I 10:56:17.282883 #13413] : :cinder: notifications.*
[-] I 10:56:17.282896 #13413] : :glance: notifications.*
[-] I 10:56:17.282908 #13413] : :neutron: notifications.*
[-] I 10:56:17.282919 #13413] : :heat: notifications.*
[-] I 10:56:17.282967 #13413] : :ironic: notifications.*
[-] I 10:56:17.282980 #13413] : :duration: 10.seconds
[-] I 10:56:17.282991 #13413] : :capacity: 50
[-] I 10:56:17.283004 #13413] : :amqp_port: 5672
[-] I 10:56:17.283016 #13413] : :event_catcher_amazon:
[-] I 10:56:17.283028 #13413] : :poll: 15.seconds
[-] I 10:56:17.283039 #13413] : :event_catcher_kubernetes:
[-] I 10:56:17.283051 #13413] : :poll: 1.seconds
[-] I 10:56:17.283062 #13413] : :enabled_events:
[-] I 10:56:17.283073 #13413] : Node:
[-] I 10:56:17.283084 #13413] : - NodeReady
[-] I 10:56:17.283096 #13413] : - NodeNotReady
[-] I 10:56:17.283130 #13413] : - rebooted
[-] I 10:56:17.283142 #13413] : Pod:
[-] I 10:56:17.283155 #13413] : - scheduled
[-] I 10:56:17.283167 #13413] : :event_catcher_openshift:
[-] I 10:56:17.283179 #13413] : :poll: 1.seconds
[-] I 10:56:17.283190 #13413] : :enabled_events:
[-] I 10:56:17.283201 #13413] : Node:
[-] I 10:56:17.283212 #13413] : - NodeReady
[-] I 10:56:17.283250 #13413] : - NodeNotReady
[-] I 10:56:17.283263 #13413] : - rebooted
[-] I 10:56:17.283275 #13413] : Pod:
[-] I 10:56:17.283286 #13413] : - scheduled
[-] I 10:56:17.283299 #13413] : :queue_worker_base:
[-] I 10:56:17.283312 #13413] : :defaults:
[-] I 10:56:17.283377 #13413] : :cpu_usage_threshold: 100.percent
[-] I 10:56:17.283391 #13413] : :dequeue_method: :drb
[-] I 10:56:17.283405 #13413] : :memory_threshold: 400.megabytes
[-] I 10:56:17.283417 #13413] : :poll_method: :normal
[-] I 10:56:17.283434 #13413] : :queue_timeout: 10.minutes
[-] I 10:56:17.283463 #13413] : :ems_metrics_collector_worker:
[-] I 10:56:17.283476 #13413] : :defaults:
[-] I 10:56:17.283529 #13413] : :count: 2
[-] I 10:56:17.283543 #13413] : :nice_delta: 3
[-] I 10:56:17.283557 #13413] : :poll_method: :escalate
[-] I 10:56:17.283570 #13413] : :ems_metrics_collector_worker_amazon:
[-] I 10:56:17.283582 #13413] : :poll_method: :escalate
[-] I 10:56:17.283595 #13413] : :ems_metrics_collector_worker_redhat:
[-] I 10:56:17.283607 #13413] : :poll_method: :escalate
[-] I 10:56:17.283660 #13413] : :ems_metrics_collector_worker_vmware:
[-] I 10:56:17.283675 #13413] : :poll_method: :escalate
[-] I 10:56:17.283687 #13413] : :ems_metrics_collector_worker_openstack:
[-] I 10:56:17.283702 #13413] : :poll_method: :escalate
[-] I 10:56:17.283715 #13413] : :ems_metrics_collector_worker_openstack_infra:
[-] I 10:56:17.283727 #13413] : :poll_method: :escalate
[-] I 10:56:17.283741 #13413] : :ems_metrics_processor_worker:
[-] I 10:56:17.283753 #13413] : :count: 2
[-] I 10:56:17.283825 #13413] : :memory_threshold: 400.megabytes
[-] I 10:56:17.283839 #13413] : :nice_delta: 7
[-] I 10:56:17.283852 #13413] : :poll_method: :escalate
[-] I 10:56:17.283864 #13413] : :ems_refresh_worker:
[-] I 10:56:17.283876 #13413] : :defaults:
[-] I 10:56:17.283888 #13413] : :memory_threshold: 2.gigabytes
[-] I 10:56:17.283901 #13413] : :nice_delta: 7
[-] I 10:56:17.283914 #13413] : :poll: 10.seconds
[-] I 10:56:17.283926 #13413] : :poll_method: :normal
[-] I 10:56:17.283963 #13413] : :queue_timeout: 120.minutes
[-] I 10:56:17.283976 #13413] : :restart_interval: 2.hours
[-] I 10:56:17.283988 #13413] : :ems_refresh_worker_amazon: {}
[-] I 10:56:17.284000 #13413] : :ems_refresh_worker_foreman_configuration: {}
[-] I 10:56:17.284013 #13413] : :ems_refresh_worker_foreman_provisioning: {}
[-] I 10:56:17.284025 #13413] : :ems_refresh_worker_kubernetes: {}
[-] I 10:56:17.284037 #13413] : :ems_refresh_worker_openshift: {}
[-] I 10:56:17.284049 #13413] : :ems_refresh_worker_microsoft: {}
[-] I 10:56:17.284092 #13413] : :ems_refresh_worker_redhat: {}
[-] I 10:56:17.284107 #13413] : :ems_refresh_worker_openstack: {}
[-] I 10:56:17.284120 #13413] : :ems_refresh_worker_openstack_infra: {}
[-] I 10:56:17.284138 #13413] : :ems_refresh_worker_vmware: {}
[-] I 10:56:17.284151 #13413] : :event_handler:
[-] I 10:56:17.284163 #13413] : :cpu_usage_threshold: 0.percent
[-] I 10:56:17.284177 #13413] : :nice_delta: 7
[-] I 10:56:17.284208 #13413] : :generic_worker:
[-] I 10:56:17.284221 #13413] : :count: 2
[-] I 10:56:17.284233 #13413] : :automate_worker:
[-] I 10:56:17.284372 #13413] : :count: 2
[-] I 10:56:17.284386 #13413] : :netapp_refresh_worker:
[-] I 10:56:17.284399 #13413] : :memory_threshold: 2.gigabytes
[-] I 10:56:17.284411 #13413] : :nice_delta: 7
[-] I 10:56:17.284423 #13413] : :poll: 10.seconds
[-] I 10:56:17.284435 #13413] : :poll_method: :normal
[-] I 10:56:17.284455 #13413] : :queue_timeout: 60.minutes
[-] I 10:56:17.284466 #13413] : :priority_worker:
[-] I 10:56:17.284478 #13413] : :count: 2
[-] I 10:56:17.284512 #13413] : :nice_delta: 1
[-] I 10:56:17.284524 #13413] : :poll: 1.seconds
[-] I 10:56:17.284536 #13413] : :reporting_worker:
[-] I 10:56:17.284546 #13413] : :count: 2
[-] I 10:56:17.284558 #13413] : :nice_delta: 7
[-] I 10:56:17.284621 #13413] : :smart_proxy_worker:
[-] I 10:56:17.284635 #13413] : :count: 2
[-] I 10:56:17.284647 #13413] : :memory_threshold: 600.megabytes
[-] I 10:56:17.284659 #13413] : :queue_timeout: 20.minutes
[-] I 10:56:17.284670 #13413] : :restart_interval: 2.hours
[-] I 10:56:17.284681 #13413] : :storage_metrics_collector_worker:
[-] I 10:56:17.284694 #13413] : :count: 2
[-] I 10:56:17.284747 #13413] : :nice_delta: 3
[-] I 10:56:17.284760 #13413] : :poll_method: :escalate
[-] I 10:56:17.284771 #13413] : :vmdb_storage_bridge_worker:
[-] I 10:56:17.284783 #13413] : :memory_threshold: 2.gigabytes
[-] I 10:56:17.284796 #13413] : :nice_delta: 7
[-] I 10:56:17.284807 #13413] : :poll: 10.seconds
[-] I 10:56:17.284819 #13413] : :poll_method: :normal
[-] I 10:56:17.284873 #13413] : :queue_timeout: 120.minutes
[-] I 10:56:17.284886 #13413] : :replication_worker:
[-] I 10:56:17.284897 #13413] : :connection_pool_size: 5
[-] I 10:56:17.284909 #13413] : :poll: 1.seconds
[-] I 10:56:17.284920 #13413] : :replication:
[-] I 10:56:17.284931 #13413] : :destination:
[-] I 10:56:17.284947 #13413] : :database: vmdb_production
[-] I 10:56:17.284960 #13413] : :username: root
[-] I 10:56:17.285012 #13413] : :exclude_tables:
[-] I 10:56:17.285024 #13413] : - assigned_server_roles
[-] I 10:56:17.285036 #13413] : - audit_events
[-] I 10:56:17.285047 #13413] : - binary_blobs
[-] I 10:56:17.285058 #13413] : - binary_blob_parts
[-] I 10:56:17.285069 #13413] : - chargeback_rate_details
[-] I 10:56:17.285083 #13413] : - chargeback_rates
[-] I 10:56:17.285135 #13413] : - conditions
[-] I 10:56:17.285149 #13413] : - conditions_miq_policies
[-] I 10:56:17.285161 #13413] : - configurations
[-] I 10:56:17.285173 #13413] : - custom_buttons
[-] I 10:56:17.285184 #13413] : - customization_specs
[-] I 10:56:17.285195 #13413] : - database_backups
[-] I 10:56:17.285206 #13413] : - event_logs
[-] I 10:56:17.285217 #13413] : - file_depots
[-] I 10:56:17.285228 #13413] : - jobs
[-] I 10:56:17.285275 #13413] : - log_files
[-] I 10:56:17.285290 #13413] : - metrics
[-] I 10:56:17.285301 #13413] : - metrics_00
[-] I 10:56:17.285312 #13413] : - metrics_01
[-] I 10:56:17.285323 #13413] : - metrics_02
[-] I 10:56:17.285334 #13413] : - metrics_03
[-] I 10:56:17.285345 #13413] : - metrics_04
[-] I 10:56:17.285355 #13413] : - metrics_05
[-] I 10:56:17.285368 #13413] : - metrics_06
[-] I 10:56:17.285379 #13413] : - metrics_07
[-] I 10:56:17.285390 #13413] : - metrics_08
[-] I 10:56:17.285401 #13413] : - metrics_09
[-] I 10:56:17.285443 #13413] : - metrics_10
[-] I 10:56:17.285454 #13413] : - metrics_11
[-] I 10:56:17.285465 #13413] : - metrics_12
[-] I 10:56:17.285476 #13413] : - metrics_13
[-] I 10:56:17.285489 #13413] : - metrics_14
[-] I 10:56:17.285500 #13413] : - metrics_15
[-] I 10:56:17.285511 #13413] : - metrics_16
[-] I 10:56:17.285559 #13413] : - metrics_17
[-] I 10:56:17.285571 #13413] : - metrics_18
[-] I 10:56:17.285582 #13413] : - metrics_19
[-] I 10:56:17.285595 #13413] : - metrics_20
[-] I 10:56:17.285606 #13413] : - metrics_21
[-] I 10:56:17.285617 #13413] : - metrics_22
[-] I 10:56:17.285633 #13413] : - metrics_23
[-] I 10:56:17.285645 #13413] : - metric_rollups
[-] I 10:56:17.285707 #13413] : - miq_actions
[-] I 10:56:17.285721 #13413] : - miq_ae_classes
[-] I 10:56:17.285733 #13413] : - miq_ae_fields
[-] I 10:56:17.285744 #13413] : - miq_ae_instances
[-] I 10:56:17.285755 #13413] : - miq_ae_methods
[-] I 10:56:17.285766 #13413] : - miq_ae_namespaces
[-] I 10:56:17.285778 #13413] : - miq_ae_values
[-] I 10:56:17.285789 #13413] : - miq_ae_workspaces
[-] I 10:56:17.285800 #13413] : - miq_alert_statuses
[-] I 10:56:17.285811 #13413] : - miq_alerts
[-] I 10:56:17.285824 #13413] : - miq_databases
[-] I 10:56:17.285835 #13413] : - miq_enterprises
[-] I 10:56:17.285873 #13413] : - miq_events
[-] I 10:56:17.285885 #13413] : - miq_globals
[-] I 10:56:17.285896 #13413] : - miq_groups
[-] I 10:56:17.285907 #13413] : - miq_license_contents
[-] I 10:56:17.285919 #13413] : - miq_policies
[-] I 10:56:17.285930 #13413] : - miq_policy_contents
[-] I 10:56:17.285941 #13413] : - miq_product_features
[-] I 10:56:17.285985 #13413] : - miq_queue
[-] I 10:56:17.285998 #13413] : - miq_roles_features
[-] I 10:56:17.286010 #13413] : - miq_report_result_details
[-] I 10:56:17.286021 #13413] : - miq_report_results
[-] I 10:56:17.286032 #13413] : - miq_reports
[-] I 10:56:17.286043 #13413] : - miq_searches
[-] I 10:56:17.286055 #13413] : - miq_servers_product_updates
[-] I 10:56:17.286067 #13413] : - miq_sets
[-] I 10:56:17.286095 #13413] : - miq_schedules
[-] I 10:56:17.286108 #13413] : - miq_shortcuts
[-] I 10:56:17.286122 #13413] : - miq_tasks
[-] I 10:56:17.286135 #13413] : - miq_user_roles
[-] I 10:56:17.286146 #13413] : - miq_widgets
[-] I 10:56:17.286158 #13413] : - miq_widget_contents
[-] I 10:56:17.286169 #13413] : - miq_workers
[-] I 10:56:17.286210 #13413] : - rss_feeds
[-] I 10:56:17.286222 #13413] : - schema_migrations
[-] I 10:56:17.286235 #13413] : - server_roles
[-] I 10:56:17.286247 #13413] : - sessions
[-] I 10:56:17.286258 #13413] : - vim_performances
[-] I 10:56:17.286271 #13413] : - vim_performance_states
[-] I 10:56:17.286287 #13413] : - vim_performance_tag_values
[-] I 10:56:17.286300 #13413] : - vmdb_database_metrics
[-] I 10:56:17.286395 #13413] : - vmdb_databases
[-] I 10:56:17.286410 #13413] : - vmdb_indexes
[-] I 10:56:17.286423 #13413] : - vmdb_metrics
[-] I 10:56:17.286436 #13413] : - vmdb_tables
[-] I 10:56:17.286447 #13413] : :options:
[-] I 10:56:17.286459 #13413] : :replication_trace: false
[-] I 10:56:17.286472 #13413] : :debug_sql: false
[-] I 10:56:17.286483 #13413] : :heartbeat_threshold: 300
[-] I 10:56:17.286496 #13413] : :schedule_worker:
[-] I 10:56:17.286508 #13413] : :authentication_check_interval: 1.day
[-] I 10:56:17.286545 #13413] : :db_diagnostics_interval: 30.minutes
[-] I 10:56:17.286560 #13413] : :ems_events_purge_interval: 1.day
[-] I 10:56:17.286572 #13413] : :evm_snapshot_delete_delay_for_job_not_found: 1.hour
[-] I 10:56:17.286585 #13413] : :evm_snapshot_interval: 1.hour
[-] I 10:56:17.286597 #13413] : :job_proxy_dispatcher_interval: 15.seconds
[-] I 10:56:17.286609 #13413] : :job_proxy_dispatcher_stale_message_check_interval: 60.seconds
[-] I 10:56:17.286622 #13413] : :job_proxy_dispatcher_stale_message_timeout: 2.minutes
[-] I 10:56:17.286634 #13413] : :job_timeout_interval: 60.seconds
[-] I 10:56:17.286645 #13413] : :log_active_configuration_interval: 1.days
[-] I 10:56:17.286658 #13413] : :log_database_statistics_interval: 1.days
[-] I 10:56:17.286673 #13413] : :memory_threshold: 250.megabytes
[-] I 10:56:17.286710 #13413] : :nice_delta: 3
[-] I 10:56:17.286725 #13413] : :orchestration_stack_retired_interval: 10.minutes
[-] I 10:56:17.286741 #13413] : :performance_collection_interval: 3.minutes
[-] I 10:56:17.286753 #13413] : :performance_collection_start_delay: 5.minutes
[-] I 10:56:17.286765 #13413] : :performance_realtime_purging_interval: 15.minutes
[-] I 10:56:17.286777 #13413] : :performance_realtime_purging_start_delay: 5.minutes
[-] I 10:56:17.286788 #13413] : :performance_rollup_purging_interval: 4.hours
[-] I 10:56:17.286800 #13413] : :performance_rollup_purging_start_delay: 5.minutes
[-] I 10:56:17.286812 #13413] : :policy_events_purge_interval: 1.day
[-] I 10:56:17.286823 #13413] : :poll: 15.seconds
[-] I 10:56:17.286863 #13413] : :server_log_stats_interval: 5.minutes
[-] I 10:56:17.286876 #13413] : :server_stats_interval: 60.seconds
[-] I 10:56:17.286887 #13413] : :service_retired_interval: 10.minutes
[-] I 10:56:17.286904 #13413] : :session_timeout_interval: 30.seconds
[-] I 10:56:17.286916 #13413] : :storage_file_collection_interval: 1.days
[-] I 10:56:17.286928 #13413] : :storage_file_collection_time_utc: 21600
[-] I 10:56:17.286939 #13413] : :vm_retired_interval: 10.minutes
[-] I 10:56:17.286951 #13413] : :vm_scan_interval: 10.minutes
[-] I 10:56:17.287000 #13413] : :smis_refresh_worker:
[-] I 10:56:17.287014 #13413] : :connection_pool_size: 5
[-] I 10:56:17.287027 #13413] : :memory_threshold: 1.gigabytes
[-] I 10:56:17.287038 #13413] : :nice_delta: 3
[-] I 10:56:17.287050 #13413] : :poll: 15.seconds
[-] I 10:56:17.287097 #13413] : :smis_update_period: 1.hours
[-] I 10:56:17.287113 #13413] : :stats_update_period: 10.minutes
[-] I 10:56:17.287125 #13413] : :status_update_period: 5.minutes
[-] I 10:56:17.287138 #13413] : :ui_worker:
[-] I 10:56:17.287152 #13413] : :connection_pool_size: 5
[-] I 10:56:17.287165 #13413] : :memory_threshold: 1.gigabytes
[-] I 10:56:17.287178 #13413] : :nice_delta: 1
[-] I 10:56:17.287191 #13413] : :poll: 60.seconds
[-] I 10:56:17.287251 #13413] : :vim_broker_worker:
[-] I 10:56:17.287266 #13413] : :heartbeat_freq: 15.seconds
[-] I 10:56:17.287279 #13413] : :memory_threshold: 2.gigabytes
[-] I 10:56:17.287292 #13413] : :nice_delta: 3
[-] I 10:56:17.287307 #13413] : :poll: 1.seconds
[-] I 10:56:17.287325 #13413] : :reconnect_retry_interval: 5.minutes
[-] I 10:56:17.287360 #13413] : :vim_broker_status_interval: 15.minutes
[-] I 10:56:17.287377 #13413] : :vim_broker_update_interval: 0.seconds
[-] I 10:56:17.287395 #13413] : :web_service_worker:
[-] I 10:56:17.287411 #13413] : :connection_pool_size: 5
[-] I 10:56:17.287524 #13413] : :memory_threshold: 1.gigabytes
[-] I 10:56:17.287539 #13413] : :nice_delta: 1
[-] I 10:56:17.287552 #13413] : :poll: 60.seconds
[-] I 10:56:17.287568 #13413] : VMDB settings END
[-] I 10:56:17.287581 #13413] : ---
[-] I 10:56:17.287597 #13413] : DATABASE settings:
** EVM vmdb_development ** 5
[-] I 10:56:17.299696 #13413] : :adapter: postgresql
[-] I 10:56:17.299745 #13413] : :encoding: utf8
[-] I 10:56:17.299762 #13413] : :username: postgres
[-] I 10:56:17.299786 #13413] : :pool: 5
[-] I 10:56:17.299801 #13413] : :wait_timeout: 5
[-] I 10:56:17.299815 #13413] : :min_messages: notice
[-] I 10:56:17.299843 #13413] : :database: vmdb_development
[-] I 10:56:17.299858 #13413] : DATABASE settings END
[-] I 10:56:17.299872 #13413] : ---
[-] I 10:56:17.311493 #13413] : MIQ(MiqServer#ntp_reload) Synchronizing ntp settings: {:server=>["0.pool.ntp.org", "1.pool.ntp.org", "2.pool.ntp.org"]}
[-] I 10:56:17.327406 #13413] : MIQ(EvmDatabase.seed) Seeding...
[-] I 10:56:17.331383 #13413] : MIQ(EvmDatabase.seed) Seeding BlacklistedEvent
[-] I 10:56:17.350498 #13413] : MIQ(EvmDatabase.seed) Seeding ChargebackRate
[-] I 10:56:17.362522 #13413] : MIQ(ChargebackRate.seed) Updating [Default] with guid=[b47a0ef0-4335-11df-aba8-001d09066d98]
[-] I 10:56:17.401273 #13413] : MIQ(ChargebackRate.seed) Updating [Default] with guid=[7d7aaf20-5214-11df-a888-001d09066d98]
[-] I 10:56:17.418967 #13413] : MIQ(EvmDatabase.seed) Seeding Classification
[-] I 10:56:17.482559 #13413] : MIQ(EvmDatabase.seed) Seeding CustomizationTemplate
[-] I 10:56:17.513704 #13413] : MIQ(EvmDatabase.seed) Seeding Dialog
[-] I 10:56:17.535151 #13413] : MIQ(EvmDatabase.seed) Seeding MiqAction
[-] I 10:56:17.552231 #13413] : MIQ(MiqAction.create_default_actions) Creating [vm_shelve]
[-] I 10:56:17.557584 #13413] : MIQ(MiqAction.create_default_actions) Creating [vm_shelve_offload]
[-] I 10:56:17.590044 #13413] : MIQ(EvmDatabase.seed) Seeding MiqAlert
[-] I 10:56:17.652468 #13413] : MIQ(EvmDatabase.seed) Seeding MiqDialog
[-] I 10:56:17.664340 #13413] : MIQ(MiqDialog.sync_from_file) [miq_host_provision_dialogs] file has been updated on disk, synchronizing with model
[-] I 10:56:17.715995 #13413] : MIQ(MiqDialog.sync_from_file) [miq_provision_amazon_dialogs_template] file has been updated on disk, synchronizing with model
[-] I 10:56:17.773093 #13413] : MIQ(MiqDialog.sync_from_file) [miq_provision_configured_system_foreman_dialogs] file has been updated on disk, synchronizing with model
[-] I 10:56:17.808195 #13413] : MIQ(MiqDialog.sync_from_file) [miq_provision_dialogs-user] file has been updated on disk, synchronizing with model
[-] I 10:56:17.918823 #13413] : MIQ(MiqDialog.sync_from_file) [miq_provision_dialogs] file has been updated on disk, synchronizing with model
[-] I 10:56:18.037539 #13413] : MIQ(MiqDialog.sync_from_file) [miq_provision_dialogs_clone_to_template] file has been updated on disk, synchronizing with model
[-] I 10:56:18.144973 #13413] : MIQ(MiqDialog.sync_from_file) [miq_provision_dialogs_clone_to_vm] file has been updated on disk, synchronizing with model
[-] I 10:56:18.242864 #13413] : MIQ(MiqDialog.sync_from_file) [miq_provision_dialogs_pre_sample] file has been updated on disk, synchronizing with model
[-] I 10:56:18.260918 #13413] : MIQ(MiqDialog.sync_from_file) [miq_provision_dialogs_template] file has been updated on disk, synchronizing with model
[-] I 10:56:18.367111 #13413] : MIQ(MiqDialog.sync_from_file) [miq_provision_microsoft_dialogs_template] file has been updated on disk, synchronizing with model
[-] I 10:56:18.472762 #13413] : MIQ(MiqDialog.sync_from_file) [miq_provision_openstack_dialogs_template] file has been updated on disk, synchronizing with model
[-] I 10:56:18.557316 #13413] : MIQ(MiqDialog.sync_from_file) [miq_provision_redhat_dialogs_clone_to_vm] file has been updated on disk, synchronizing with model
[-] I 10:56:18.666061 #13413] : MIQ(MiqDialog.sync_from_file) [miq_provision_redhat_dialogs_template] file has been updated on disk, synchronizing with model
[-] I 10:56:18.751464 #13413] : MIQ(MiqDialog.sync_from_file) [vm_migrate_dialogs] file has been updated on disk, synchronizing with model
[-] I 10:56:18.797430 #13413] : MIQ(EvmDatabase.seed) Seeding MiqEventDefinition
[-] I 10:56:19.660365 #13413] : MIQ(EvmDatabase.seed) Seeding MiqEventDefinitionSet
[-] I 10:56:19.690520 #13413] : MIQ(EvmDatabase.seed) Seeding MiqPolicy
[-] I 10:56:19.705265 #13413] : MIQ(EvmDatabase.seed) Seeding MiqPolicySet
[-] I 10:56:19.711170 #13413] : MIQ(EvmDatabase.seed) Seeding MiqSearch
[-] I 10:56:20.170817 #13413] : MIQ(EvmDatabase.seed) Seeding MiqShortcut
[-] I 10:56:20.208615 #13413] : MIQ(EvmDatabase.seed) Seeding MiqWidgetSet
[-] I 10:56:20.216299 #13413] : Widget Set: [Default Dashboard] file has been updated on disk, synchronizing with model
[-] I 10:56:20.229016 #13413] : MIQ(EvmDatabase.seed) Seeding PxeImageType
[-] I 10:56:20.238742 #13413] : MIQ(EvmDatabase.seed) Seeding ScanItem
[-] I 10:56:20.249748 #13413] : Scan Item: [sample_category] file has been updated on disk, synchronizing with model
[-] I 10:56:20.254894 #13413] : Scan Item: [sample_file] file has been updated on disk, synchronizing with model
[-] I 10:56:20.259352 #13413] : Scan Item: [sample_host_event_log] file has been updated on disk, synchronizing with model
[-] I 10:56:20.265700 #13413] : Scan Item: [sample_host_file] file has been updated on disk, synchronizing with model
[-] I 10:56:20.285906 #13413] : Scan Item: [sample_nt_event_log] file has been updated on disk, synchronizing with model
[-] I 10:56:20.294102 #13413] : Scan Item: [sample_registry] file has been updated on disk, synchronizing with model
[-] I 10:56:20.374071 #13413] : MIQ(EvmDatabase.seed) Seeding TimeProfile
[-] I 10:56:20.386642 #13413] : MIQ(EvmDatabase.seed) Seeding MiqAeDatastore
[-] I 10:56:20.437079 #13413] : MIQ(EvmDatabase.seed) Seeding... Complete
[-] I 10:56:20.485845 #13413] : MIQ(MiqEvent.raise_evm_event) Event Raised [evm_server_start]
[-] I 10:56:20.513069 #13413] : MIQ(MiqEvent.raise_evm_event) Alert for Event [evm_server_start]
[-] I 10:56:20.513155 #13413] : MIQ(MiqAlert.evaluate_alerts) [evm_server_start] Target: MiqServer Name: [EVM], Id: [3]
[-] I 10:56:20.525509 #13413] : MIQ(MiqServer#start) Server starting in Normal mode.
** Server starting in Normal mode.
** EVM vmdb_development ** 6
[-] I 10:56:20.616018 #13413] : MIQ(MiqServer#make_master_server) Master server has not been set. Attempting takeover as new master server.
[-] I 10:56:20.621638 #13413] : MIQ(MiqServer#make_master_server) This server is now set as the master server
[-] I 10:56:20.629764 #13413] : MIQ(MiqQueue.put) Message id: [3], id: [], Zone: [], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqEvent.raise_evm_event], Timeout: [600], Priority: [100], State: [ready], Deliver On: [], Data: [], Args: [["MiqServer", 3], "evm_server_is_master", {:event_details=>"MiqServer [EVM] with ID: [3] has taken over master"}]
[-] I 10:56:20.660234 #13413] : MIQ(AssignedServerRole#activate) Activating Role <ems_inventory> on Server <EVM>
[-] I 10:56:20.662730 #13413] : MIQ(AssignedServerRole#activate) Activating Role <ems_operations> on Server <EVM>
[-] I 10:56:20.664874 #13413] : MIQ(AssignedServerRole#activate) Activating Role <event> on Server <EVM>
[-] I 10:56:20.667032 #13413] : MIQ(AssignedServerRole#activate) Activating Role <smartstate> on Server <EVM>
[-] I 10:56:20.682554 #13413] : MIQ(AssignedServerRole#activate) Activating Role <automate> on Server <EVM>
[-] I 10:56:20.684614 #13413] : MIQ(AssignedServerRole#activate) Activating Role <database_operations> on Server <EVM>
[-] I 10:56:20.686671 #13413] : MIQ(AssignedServerRole#activate) Activating Role <reporting> on Server <EVM>
[-] I 10:56:20.689071 #13413] : MIQ(AssignedServerRole#activate) Activating Role <scheduler> on Server <EVM>
[-] I 10:56:20.691673 #13413] : MIQ(AssignedServerRole#activate) Activating Role <user_interface> on Server <EVM>
[-] I 10:56:20.694220 #13413] : MIQ(AssignedServerRole#activate) Activating Role <web_services> on Server <EVM>
[-] I 10:56:20.747013 #13413] : MIQ(Configuration.create_or_update) Skipping update since no settings are changed for server configuration: id: [1], typ: [vmdb], miq_server_id: [3]
[-] I 10:56:20.762125 #13413] : MIQ(VMDB::Config#save) Saved Config [vmdb] from database in file: [/Users/kbrock/src/manageiq/config/vmdb.yml.db]
[-] I 10:56:20.770059 #13413] : MIQ(MiqServer#ntp_reload_queue) Previous ntp_reload is still running, skipping...Resource: [MiqServer], id: [3]
[-] I 10:56:20.777415 #13413] : MIQ(MiqQueue.put_or_update) Message id: [2] updated with following: {:queue_name=>"generic", :state=>"ready", :zone=>"default", :class_name=>"MiqServer", :instance_id=>3, :method_name=>"ntp_reload", :server_guid=>"c69aab4c-4755-11e5-8436-b8e856479e14", :priority=>20, :args=>[{:server=>["0.pool.ntp.org", "1.pool.ntp.org", "2.pool.ntp.org"]}]}
[-] I 10:56:20.777532 #13413] : MIQ(MiqQueue.put_or_update) Message id: [2], id: [], Zone: [default], Role: [], Server: [c69aab4c-4755-11e5-8436-b8e856479e14], Ident: [generic], Target id: [], Instance id: [3], Task id: [], Command: [MiqServer.ntp_reload], Timeout: [600], Priority: [20], State: [ready], Deliver On: [], Data: [], Args: [{:server=>["0.pool.ntp.org", "1.pool.ntp.org", "2.pool.ntp.org"]}], Requeued
[-] I 10:56:20.777593 #13413] : MIQ(MiqServer.atStartup) Invoking startup methods
[-] I 10:56:20.777705 #13413] : MIQ(MiqServer.atStartup) Invoking startup method for MiqRegion
[-] I 10:56:20.780625 #13413] : MIQ(MiqRegion.atStartup) Region: [0], name: [Region 0], Under Management: VMs: [0], Hosts: [0], Sockets: [0]
[-] I 10:56:20.792649 #13413] : MIQ(MiqRegion.atStartup) Region: [0], name: [Region 0], Not Under Management: VMs: [0], Hosts: [0], Sockets: [0]
[-] I 10:56:20.792752 #13413] : MIQ(MiqServer.atStartup) Invoking startup method for MiqWorker
[-] I 10:56:20.795753 #13413] : MIQ(MiqServer.atStartup) Invoking startup method for MiqQueue
[-] I 10:56:20.795823 #13413] : MIQ(MiqQueue.atStartup) Cleaning up queue messages...
[-] I 10:56:20.796554 #13413] : MIQ(MiqQueue.atStartup) Cleaning up queue messages... Complete
[-] I 10:56:20.804500 #13413] : MIQ(MiqServer.atStartup) Invoking startup method for MiqReportResult
[-] I 10:56:20.804563 #13413] : MIQ(MiqReportResult.atStartup) Purging adhoc report results...
[-] I 10:56:20.808363 #13413] : MIQ(MiqReportResult.atStartup) Purging adhoc report results... complete
[-] I 10:56:20.815156 #13413] : MIQ(MiqQueue.put) Message id: [4], id: [], Zone: [default], Role: [], Server: [c69aab4c-4755-11e5-8436-b8e856479e14], Ident: [generic], Target id: [], Instance id: [3], Task id: [], Command: [MiqServer.delete_active_log_collections], Timeout: [600], Priority: [20], State: [ready], Deliver On: [], Data: [], Args: []
[-] I 10:56:20.819267 #13413] : MIQ(Vmdb::Loggers.apply_config) Log level for development.log has been changed to [INFO]
[-] I 10:56:21.011648 #13413] : :kill_algorithm:
[-] I 10:56:21.011701 #13413] : :name: :used_swap_percent_gt_value
[-] I 10:56:21.011717 #13413] : :value: 80
[-] I 10:56:21.011816 #13413] : :miq_server_time_threshold: 120
[-] I 10:56:21.011829 #13413] : :nice_delta: 1
[-] I 10:56:21.011841 #13413] : :poll: 2
[-] I 10:56:21.011853 #13413] : :start_algorithm:
[-] I 10:56:21.011864 #13413] : :name: :used_swap_percent_lt_value
[-] I 10:56:21.011875 #13413] : :value: 60
[-] I 10:56:21.011886 #13413] : :sync_interval: 1800
[-] I 10:56:21.011897 #13413] : :wait_for_started_timeout: 600
[-] I 10:56:21.224271 #13413] : MIQ(MiqEventHandler.sync_workers) Workers are being synchronized: Current #: [0], Desired #: [1]
[-] I 10:56:21.389120 #13413] : :kill_algorithm:
[-] I 10:56:21.389173 #13413] : :name: :used_swap_percent_gt_value
[-] I 10:56:21.389190 #13413] : :value: 80
[-] I 10:56:21.389213 #13413] : :miq_server_time_threshold: 120
[-] I 10:56:21.389225 #13413] : :nice_delta: 1
[-] I 10:56:21.389237 #13413] : :poll: 2
[-] I 10:56:21.389300 #13413] : :start_algorithm:
[-] I 10:56:21.389313 #13413] : :name: :used_swap_percent_lt_value
[-] I 10:56:21.389325 #13413] : :value: 60
[-] I 10:56:21.389336 #13413] : :sync_interval: 1800
[-] I 10:56:21.389348 #13413] : :wait_for_started_timeout: 600
[-] I 10:56:21.442359 #13413] : MIQ(MiqQueue.put) Message id: [5], id: [], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqEvent.raise_evm_event], Timeout: [600], Priority: [100], State: [ready], Deliver On: [], Data: [], Args: [["MiqServer", 3], "evm_worker_start", {:event_details=>"Worker started: ID [1], PID [], GUID [1ad4ce02-5315-11e5-8e34-b8e856479e14]", :type=>"MiqEventHandler"}]
[-] I 10:56:21.449712 #13413] : MIQ(MiqEventHandler#start) Worker started: ID [1], PID [], GUID [1ad4ce02-5315-11e5-8e34-b8e856479e14]
[-] I 10:56:21.457464 #13413] : MIQ(MiqGenericWorker.sync_workers) Workers are being synchronized: Current #: [0], Desired #: [2]
[-] I 10:56:21.639411 #13413] : :kill_algorithm:
[-] I 10:56:21.639466 #13413] : :name: :used_swap_percent_gt_value
[-] I 10:56:21.639484 #13413] : :value: 80
[-] I 10:56:21.639499 #13413] : :miq_server_time_threshold: 120
[-] I 10:56:21.639513 #13413] : :nice_delta: 1
[-] I 10:56:21.639528 #13413] : :poll: 2
[-] I 10:56:21.639541 #13413] : :start_algorithm:
[-] I 10:56:21.639610 #13413] : :name: :used_swap_percent_lt_value
[-] I 10:56:21.639640 #13413] : :value: 60
[-] I 10:56:21.639657 #13413] : :sync_interval: 1800
[-] I 10:56:21.639678 #13413] : :wait_for_started_timeout: 600
[-] I 10:56:21.660433 #13413] : MIQ(MiqQueue.put) Message id: [6], id: [], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqEvent.raise_evm_event], Timeout: [600], Priority: [100], State: [ready], Deliver On: [], Data: [], Args: [["MiqServer", 3], "evm_worker_start", {:event_details=>"Worker started: ID [2], PID [], GUID [1af71d86-5315-11e5-8e34-b8e856479e14]", :type=>"MiqGenericWorker"}]
[-] I 10:56:21.665770 #13413] : MIQ(MiqGenericWorker#start) Worker started: ID [2], PID [], GUID [1af71d86-5315-11e5-8e34-b8e856479e14]
[-] I 10:56:21.675179 #13413] : MIQ(MiqQueue.put) Message id: [7], id: [], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqEvent.raise_evm_event], Timeout: [600], Priority: [100], State: [ready], Deliver On: [], Data: [], Args: [["MiqServer", 3], "evm_worker_start", {:event_details=>"Worker started: ID [3], PID [], GUID [1af9dab2-5315-11e5-8e34-b8e856479e14]", :type=>"MiqGenericWorker"}]
[-] I 10:56:21.680778 #13413] : MIQ(MiqGenericWorker#start) Worker started: ID [3], PID [], GUID [1af9dab2-5315-11e5-8e34-b8e856479e14]
[-] I 10:56:21.693821 #13413] : MIQ(MiqPriorityWorker.sync_workers) Workers are being synchronized: Current #: [0], Desired #: [2]
[-] I 10:56:21.874213 #13413] : :kill_algorithm:
[-] I 10:56:21.874254 #13413] : :name: :used_swap_percent_gt_value
[-] I 10:56:21.874271 #13413] : :value: 80
[-] I 10:56:21.874289 #13413] : :miq_server_time_threshold: 120
[-] I 10:56:21.874454 #13413] : :nice_delta: 1
[-] I 10:56:21.874477 #13413] : :poll: 2
[-] I 10:56:21.874498 #13413] : :start_algorithm:
[-] I 10:56:21.874524 #13413] : :name: :used_swap_percent_lt_value
[-] I 10:56:21.874546 #13413] : :value: 60
[-] I 10:56:21.874568 #13413] : :sync_interval: 1800
[-] I 10:56:21.874597 #13413] : :wait_for_started_timeout: 600
[-] I 10:56:21.898572 #13413] : MIQ(MiqQueue.put) Message id: [8], id: [], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqEvent.raise_evm_event], Timeout: [600], Priority: [100], State: [ready], Deliver On: [], Data: [], Args: [["MiqServer", 3], "evm_worker_start", {:event_details=>"Worker started: ID [4], PID [], GUID [1b1b246a-5315-11e5-8e34-b8e856479e14]", :type=>"MiqPriorityWorker"}]
[-] I 10:56:21.904809 #13413] : MIQ(MiqPriorityWorker#start) Worker started: ID [4], PID [], GUID [1b1b246a-5315-11e5-8e34-b8e856479e14]
[-] I 10:56:21.920241 #13413] : MIQ(MiqQueue.put) Message id: [9], id: [], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqEvent.raise_evm_event], Timeout: [600], Priority: [100], State: [ready], Deliver On: [], Data: [], Args: [["MiqServer", 3], "evm_worker_start", {:event_details=>"Worker started: ID [5], PID [], GUID [1b1e67ba-5315-11e5-8e34-b8e856479e14]", :type=>"MiqPriorityWorker"}]
[-] I 10:56:21.926357 #13413] : MIQ(MiqPriorityWorker#start) Worker started: ID [5], PID [], GUID [1b1e67ba-5315-11e5-8e34-b8e856479e14]
[-] I 10:56:21.942053 #13413] : MIQ(MiqReportingWorker.sync_workers) Workers are being synchronized: Current #: [0], Desired #: [2]
[-] I 10:56:22.174951 #13413] : :kill_algorithm:
[-] I 10:56:22.175009 #13413] : :name: :used_swap_percent_gt_value
[-] I 10:56:22.175042 #13413] : :value: 80
[-] I 10:56:22.175068 #13413] : :miq_server_time_threshold: 120
[-] I 10:56:22.175091 #13413] : :nice_delta: 1
[-] I 10:56:22.175112 #13413] : :poll: 2
[-] I 10:56:22.175134 #13413] : :start_algorithm:
[-] I 10:56:22.175156 #13413] : :name: :used_swap_percent_lt_value
[-] I 10:56:22.175181 #13413] : :value: 60
[-] I 10:56:22.175202 #13413] : :sync_interval: 1800
[-] I 10:56:22.175224 #13413] : :wait_for_started_timeout: 600
[-] I 10:56:22.210093 #13413] : MIQ(MiqQueue.put) Message id: [10], id: [], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqEvent.raise_evm_event], Timeout: [600], Priority: [100], State: [ready], Deliver On: [], Data: [], Args: [["MiqServer", 3], "evm_worker_start", {:event_details=>"Worker started: ID [6], PID [], GUID [1b49f6aa-5315-11e5-8e34-b8e856479e14]", :type=>"MiqReportingWorker"}]
[-] I 10:56:22.217204 #13413] : MIQ(MiqReportingWorker#start) Worker started: ID [6], PID [], GUID [1b49f6aa-5315-11e5-8e34-b8e856479e14]
[-] I 10:56:22.236855 #13413] : MIQ(MiqQueue.put) Message id: [11], id: [], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqEvent.raise_evm_event], Timeout: [600], Priority: [100], State: [ready], Deliver On: [], Data: [], Args: [["MiqServer", 3], "evm_worker_start", {:event_details=>"Worker started: ID [7], PID [], GUID [1b4f11f8-5315-11e5-8e34-b8e856479e14]", :type=>"MiqReportingWorker"}]
[-] I 10:56:22.245590 #13413] : MIQ(MiqReportingWorker#start) Worker started: ID [7], PID [], GUID [1b4f11f8-5315-11e5-8e34-b8e856479e14]
[-] I 10:56:22.248055 #13413] : MIQ(MiqScheduleWorker.sync_workers) Workers are being synchronized: Current #: [0], Desired #: [1]
[-] I 10:56:22.542319 #13413] : :kill_algorithm:
[-] I 10:56:22.542380 #13413] : :name: :used_swap_percent_gt_value
[-] I 10:56:22.542414 #13413] : :value: 80
[-] I 10:56:22.542460 #13413] : :miq_server_time_threshold: 120
[-] I 10:56:22.542487 #13413] : :nice_delta: 1
[-] I 10:56:22.542512 #13413] : :poll: 2
[-] I 10:56:22.542556 #13413] : :start_algorithm:
[-] I 10:56:22.542582 #13413] : :name: :used_swap_percent_lt_value
[-] I 10:56:22.542606 #13413] : :value: 60
[-] I 10:56:22.542635 #13413] : :sync_interval: 1800
[-] I 10:56:22.542662 #13413] : :wait_for_started_timeout: 600
[-] I 10:56:22.645109 #13413] : MIQ(MiqQueue.put) Message id: [12], id: [], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqEvent.raise_evm_event], Timeout: [600], Priority: [100], State: [ready], Deliver On: [], Data: [], Args: [["MiqServer", 3], "evm_worker_start", {:event_details=>"Worker started: ID [8], PID [], GUID [1b8c860a-5315-11e5-8e34-b8e856479e14]", :type=>"MiqScheduleWorker"}]
[-] I 10:56:22.652932 #13413] : MIQ(MiqScheduleWorker#start) Worker started: ID [8], PID [], GUID [1b8c860a-5315-11e5-8e34-b8e856479e14]
[-] I 10:56:22.673335 #13413] : MIQ(MiqUiWorker.sync_workers) Workers are being synchronized: Current #: [0], Desired #: [1]
[-] I 10:56:22.941831 #13413] : :kill_algorithm:
[-] I 10:56:22.943352 #13413] : :name: :used_swap_percent_gt_value
[-] I 10:56:22.945121 #13413] : :value: 80
[-] I 10:56:22.945209 #13413] : :miq_server_time_threshold: 120
[-] I 10:56:22.945489 #13413] : :nice_delta: 1
[-] I 10:56:22.945569 #13413] : :poll: 2
[-] I 10:56:22.945713 #13413] : :start_algorithm:
[-] I 10:56:22.945846 #13413] : :name: :used_swap_percent_lt_value
[-] I 10:56:22.945966 #13413] : :value: 60
[-] I 10:56:22.946031 #13413] : :sync_interval: 1800
[-] I 10:56:22.946256 #13413] : :wait_for_started_timeout: 600
[-] I 10:56:22.946616 #13413] : MIQ(MiqUiWorker.sync_workers) Reserved port=3000, Current ports in use: []
[-] I 10:56:22.994288 #13413] : MIQ(MiqQueue.put) Message id: [13], id: [], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqEvent.raise_evm_event], Timeout: [600], Priority: [100], State: [ready], Deliver On: [], Data: [], Args: [["MiqServer", 3], "evm_worker_start", {:event_details=>"Worker started: ID [9], PID [], GUID [1bc08720-5315-11e5-8e34-b8e856479e14]", :type=>"MiqUiWorker"}]
[-] I 10:56:23.242850 #13413] : MIQ(MiqUiWorker#start) Worker started: ID [9], PID [], GUID [1bc08720-5315-11e5-8e34-b8e856479e14]
[-] I 10:56:23.260288 #13413] : MIQ(MiqWebServiceWorker.sync_workers) Workers are being synchronized: Current #: [0], Desired #: [1]
[-] I 10:56:23.525890 #13413] : :kill_algorithm:
[-] I 10:56:23.525954 #13413] : :name: :used_swap_percent_gt_value
[-] I 10:56:23.525984 #13413] : :value: 80
[-] I 10:56:23.526010 #13413] : :miq_server_time_threshold: 120
[-] I 10:56:23.526034 #13413] : :nice_delta: 1
[-] I 10:56:23.526081 #13413] : :poll: 2
[-] I 10:56:23.526111 #13413] : :start_algorithm:
[-] I 10:56:23.526137 #13413] : :name: :used_swap_percent_lt_value
[-] I 10:56:23.526161 #13413] : :value: 60
[-] I 10:56:23.526182 #13413] : :sync_interval: 1800
[-] I 10:56:23.526205 #13413] : :wait_for_started_timeout: 600
[-] I 10:56:23.526386 #13413] : MIQ(MiqWebServiceWorker.sync_workers) Reserved port=4000, Current ports in use: []
[-] I 10:56:23.591603 #13413] : MIQ(MiqQueue.put) Message id: [14], id: [], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqEvent.raise_evm_event], Timeout: [600], Priority: [100], State: [ready], Deliver On: [], Data: [], Args: [["MiqServer", 3], "evm_worker_start", {:event_details=>"Worker started: ID [10], PID [], GUID [1c1ac9c4-5315-11e5-8e34-b8e856479e14]", :type=>"MiqWebServiceWorker"}]
[-] I 10:56:23.600775 #13413] : MIQ(MiqWebServiceWorker#start) Worker started: ID [10], PID [], GUID [1c1ac9c4-5315-11e5-8e34-b8e856479e14]
[-] I 10:56:23.613927 #13413] : MIQ(MiqAutomateWorker.sync_workers) Workers are being synchronized: Current #: [0], Desired #: [2]
[-] I 10:56:23.926379 #13413] : :kill_algorithm:
[-] I 10:56:23.926443 #13413] : :name: :used_swap_percent_gt_value
[-] I 10:56:23.926481 #13413] : :value: 80
[-] I 10:56:23.926512 #13413] : :miq_server_time_threshold: 120
[-] I 10:56:23.926582 #13413] : :nice_delta: 1
[-] I 10:56:23.926632 #13413] : :poll: 2
[-] I 10:56:23.926660 #13413] : :start_algorithm:
[-] I 10:56:23.926685 #13413] : :name: :used_swap_percent_lt_value
[-] I 10:56:23.926713 #13413] : :value: 60
[-] I 10:56:23.926741 #13413] : :sync_interval: 1800
[-] I 10:56:23.926767 #13413] : :wait_for_started_timeout: 600
[-] I 10:56:23.993352 #13413] : MIQ(MiqQueue.put) Message id: [15], id: [], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqEvent.raise_evm_event], Timeout: [600], Priority: [100], State: [ready], Deliver On: [], Data: [], Args: [["MiqServer", 3], "evm_worker_start", {:event_details=>"Worker started: ID [11], PID [], GUID [1c5a0e36-5315-11e5-8e34-b8e856479e14]", :type=>"MiqAutomateWorker"}]
[-] I 10:56:24.002462 #13413] : MIQ(MiqAutomateWorker#start) Worker started: ID [11], PID [], GUID [1c5a0e36-5315-11e5-8e34-b8e856479e14]
[-] I 10:56:24.016103 #13413] : MIQ(MiqQueue.put) Message id: [16], id: [], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqEvent.raise_evm_event], Timeout: [600], Priority: [100], State: [ready], Deliver On: [], Data: [], Args: [["MiqServer", 3], "evm_worker_start", {:event_details=>"Worker started: ID [12], PID [], GUID [1c5e7804-5315-11e5-8e34-b8e856479e14]", :type=>"MiqAutomateWorker"}]
[-] I 10:56:24.025107 #13413] : MIQ(MiqAutomateWorker#start) Worker started: ID [12], PID [], GUID [1c5e7804-5315-11e5-8e34-b8e856479e14]
[-] I 10:56:24.028604 #13413] : MIQ(MiqServer#wait_for_started_workers) Waiting for the following workers to start: MiqAutomateWorker (2), MiqEventHandler (1), MiqGenericWorker (2), MiqPriorityWorker (2), MiqReportingWorker (2), MiqScheduleWorker (1), MiqUiWorker (1), MiqWebServiceWorker (1)
[-] I 10:56:30.749249 #13446] : MIQ(Vmdb::Loggers.apply_config) Log level for vim.log has been changed to [WARN]
** EVM vmdb_development ** 1
[-] I 10:56:31.259800 #13449] : MIQ(Vmdb::Loggers.apply_config) Log level for vim.log has been changed to [WARN]
[-] I 10:56:31.262177 #13448] : MIQ(Vmdb::Loggers.apply_config) Log level for vim.log has been changed to [WARN]
** EVM vmdb_development ** 1
** EVM vmdb_development ** 1
[-] I 10:56:32.042271 #13452] : MIQ(Vmdb::Loggers.apply_config) Log level for vim.log has been changed to [WARN]
[-] I 10:56:32.043197 #13453] : MIQ(Vmdb::Loggers.apply_config) Log level for vim.log has been changed to [WARN]
** EVM vmdb_development ** 1
** EVM vmdb_development ** 1
[-] I 10:56:32.789184 #13457] : MIQ(Vmdb::Loggers.apply_config) Log level for vim.log has been changed to [WARN]
[-] I 10:56:32.789887 #13456] : MIQ(Vmdb::Loggers.apply_config) Log level for vim.log has been changed to [WARN]
** EVM vmdb_development ** 1
** EVM vmdb_development ** 1
[-] I 10:56:33.591991 #13460] : MIQ(Vmdb::Loggers.apply_config) Log level for vim.log has been changed to [WARN]
** EVM vmdb_development ** 1
[-] I 10:56:33.989421 #13446] : MIQ(Vmdb::Initializer.init) - Program Name: /Users/kbrock/src/manageiq/bin/rails, PID: 13446, ENV['MIQ_GUID']: 1ad4ce02-5315-11e5-8e34-b8e856479e14, ENV['EVMSERVER']:
[-] I 10:56:33.998827 #13446] : MIQ(Vmdb::Initializer.init) - Init complete
[-] I 10:56:34.075661 #13462] : MIQ(Vmdb::Loggers.apply_config) Log level for vim.log has been changed to [WARN]
** EVM vmdb_development ** 1
[-] I 10:56:34.479399 #13448] : MIQ(Vmdb::Initializer.init) - Program Name: /Users/kbrock/src/manageiq/bin/rails, PID: 13448, ENV['MIQ_GUID']: 1af71d86-5315-11e5-8e34-b8e856479e14, ENV['EVMSERVER']:
[-] I 10:56:34.482952 #13449] : MIQ(Vmdb::Initializer.init) - Program Name: /Users/kbrock/src/manageiq/bin/rails, PID: 13449, ENV['MIQ_GUID']: 1af9dab2-5315-11e5-8e34-b8e856479e14, ENV['EVMSERVER']:
[-] I 10:56:34.492687 #13448] : MIQ(Vmdb::Initializer.init) - Init complete
[-] I 10:56:34.495940 #13449] : MIQ(Vmdb::Initializer.init) - Init complete
[-] I 10:56:34.963825 #13464] : MIQ(Vmdb::Loggers.apply_config) Log level for vim.log has been changed to [WARN]
[-] I 10:56:35.121959 #13466] : MIQ(Vmdb::Loggers.apply_config) Log level for vim.log has been changed to [WARN]
[-] I 10:56:35.126403 #13467] : MIQ(Vmdb::Loggers.apply_config) Log level for vim.log has been changed to [WARN]
[-] I 10:56:35.282790 #13453] : MIQ(Vmdb::Initializer.init) - Program Name: /Users/kbrock/src/manageiq/bin/rails, PID: 13453, ENV['MIQ_GUID']: 1b1e67ba-5315-11e5-8e34-b8e856479e14, ENV['EVMSERVER']:
[-] I 10:56:35.284501 #13452] : MIQ(Vmdb::Initializer.init) - Program Name: /Users/kbrock/src/manageiq/bin/rails, PID: 13452, ENV['MIQ_GUID']: 1b1b246a-5315-11e5-8e34-b8e856479e14, ENV['EVMSERVER']:
[-] I 10:56:35.289137 #13453] : MIQ(Vmdb::Initializer.init) - Init complete
** EVM vmdb_development ** 1
[-] I 10:56:35.292015 #13452] : MIQ(Vmdb::Initializer.init) - Init complete
** EVM vmdb_development ** 1
** EVM vmdb_development ** 1
[-] I 10:56:36.028967 #13456] : MIQ(Vmdb::Initializer.init) - Program Name: /Users/kbrock/src/manageiq/bin/rails, PID: 13456, ENV['MIQ_GUID']: 1b49f6aa-5315-11e5-8e34-b8e856479e14, ENV['EVMSERVER']:
[-] I 10:56:36.035011 #13456] : MIQ(Vmdb::Initializer.init) - Init complete
[-] I 10:56:36.037687 #13457] : MIQ(Vmdb::Initializer.init) - Program Name: /Users/kbrock/src/manageiq/bin/rails, PID: 13457, ENV['MIQ_GUID']: 1b4f11f8-5315-11e5-8e34-b8e856479e14, ENV['EVMSERVER']:
[-] I 10:56:36.043570 #13457] : MIQ(Vmdb::Initializer.init) - Init complete
[-] I 10:56:36.809134 #13462] : MIQ(SessionStore) Using session_store: ActionDispatch::Session::DalliStore
[-] I 10:56:36.821984 #13460] : MIQ(Vmdb::Initializer.init) - Program Name: /Users/kbrock/src/manageiq/bin/rails, PID: 13460, ENV['MIQ_GUID']: 1b8c860a-5315-11e5-8e34-b8e856479e14, ENV['EVMSERVER']:
[-] I 10:56:36.832205 #13460] : MIQ(Vmdb::Initializer.init) - Init complete
[-] I 10:56:37.437439 #13462] : MIQ(Vmdb::Initializer.init) - Program Name: /Users/kbrock/src/manageiq/bin/rails, PID: 13462, ENV['MIQ_GUID']: 1bc08720-5315-11e5-8e34-b8e856479e14, ENV['EVMSERVER']:
[-] I 10:56:37.700551 #13464] : MIQ(SessionStore) Using session_store: ActionDispatch::Session::DalliStore
[-] I 10:56:38.321410 #13464] : MIQ(Vmdb::Initializer.init) - Program Name: /Users/kbrock/src/manageiq/bin/rails, PID: 13464, ENV['MIQ_GUID']: 1c1ac9c4-5315-11e5-8e34-b8e856479e14, ENV['EVMSERVER']:
[-] I 10:56:38.367854 #13467] : MIQ(Vmdb::Initializer.init) - Program Name: /Users/kbrock/src/manageiq/bin/rails, PID: 13467, ENV['MIQ_GUID']: 1c5e7804-5315-11e5-8e34-b8e856479e14, ENV['EVMSERVER']:
[-] I 10:56:38.382961 #13467] : MIQ(Vmdb::Initializer.init) - Init complete
[-] I 10:56:38.409541 #13466] : MIQ(Vmdb::Initializer.init) - Program Name: /Users/kbrock/src/manageiq/bin/rails, PID: 13466, ENV['MIQ_GUID']: 1c5a0e36-5315-11e5-8e34-b8e856479e14, ENV['EVMSERVER']:
[-] I 10:56:38.415363 #13466] : MIQ(Vmdb::Initializer.init) - Init complete
[-] I 10:56:40.937944 #13446] : MIQ(Vmdb::Loggers.apply_config) Log level for development.log has been changed to [INFO]
[-] I 10:56:40.953270 #13446] : MIQ(EventHandler#sync_config) ID [1], PID [13446], GUID [1ad4ce02-5315-11e5-8e34-b8e856479e14], Zone [default], Active Roles [automate,database_operations,database_owner,ems_inventory,ems_operations,event,reporting,scheduler,smartstate,user_interface,web_services], Assigned Roles [automate,database_operations,database_owner,ems_inventory,ems_operations,event,reporting,scheduler,smartstate,user_interface,web_services], Configuration:
[-] I 10:56:40.954205 #13446] : :count: 1
[-] I 10:56:40.954295 #13446] : :gc_interval: 900
[-] I 10:56:40.954335 #13446] : :heartbeat_freq: 60
[-] I 10:56:40.954366 #13446] : :heartbeat_timeout: 120
[-] I 10:56:40.954393 #13446] : :memory_threshold: 419430400
[-] I 10:56:40.954420 #13446] : :nice_delta: 7
[-] I 10:56:40.954445 #13446] : :parent_time_threshold: 180
[-] I 10:56:40.954469 #13446] : :poll: 3
[-] I 10:56:40.954494 #13446] : :poll_escalate_max: 30
[-] I 10:56:40.954518 #13446] : :poll_method: :normal
[-] I 10:56:40.954620 #13446] : :restart_interval: 0
[-] I 10:56:40.954658 #13446] : :starting_timeout: 600
[-] I 10:56:40.954689 #13446] : :cpu_usage_threshold: 0
[-] I 10:56:40.954738 #13446] : :dequeue_method: :drb
[-] I 10:56:40.954774 #13446] : :queue_timeout: 600
[-] I 10:56:40.954801 #13446] : ---
[-] I 10:56:40.955141 #13446] : :guid: 1ad4ce02-5315-11e5-8e34-b8e856479e14
[-] I 10:56:41.278681 #13446] : EventHandler started. ID [1], PID [13446], GUID [1ad4ce02-5315-11e5-8e34-b8e856479e14], Zone [default], Role [automate,database_operations,database_owner,ems_inventory,ems_operations,event,reporting,scheduler,smartstate,user_interface,web_services]
[-] I 10:56:41.278769 #13446] : MIQ(EventHandler#do_wait_for_worker_monitor) MIQ(EventHandler) Checking that worker monitor has started before doing work
[-] I 10:56:41.282335 #13446] : MIQ(EventHandler#worker_monitor_drb) MIQ(EventHandler) Initializing DRb Connection to MiqServer with ID=[3], NAME=[EVM], PID=[13413], GUID=[c69aab4c-4755-11e5-8436-b8e856479e14] DRb URI=[druby://127.0.0.1]
[-] I 10:56:41.464790 #13449] : MIQ(Vmdb::Loggers.apply_config) Log level for development.log has been changed to [INFO]
[-] I 10:56:41.486840 #13449] : MIQ(GenericWorker#sync_config) ID [3], PID [13449], GUID [1af9dab2-5315-11e5-8e34-b8e856479e14], Zone [default], Active Roles [automate,database_operations,database_owner,ems_inventory,ems_operations,event,reporting,scheduler,smartstate,user_interface,web_services], Assigned Roles [automate,database_operations,database_owner,ems_inventory,ems_operations,event,reporting,scheduler,smartstate,user_interface,web_services], Configuration:
[-] I 10:56:41.488081 #13449] : :count: 2
[-] I 10:56:41.488139 #13449] : :gc_interval: 900
[-] I 10:56:41.488174 #13449] : :heartbeat_freq: 60
[-] I 10:56:41.488237 #13449] : :heartbeat_timeout: 120
[-] I 10:56:41.488294 #13449] : :memory_threshold: 419430400
[-] I 10:56:41.488330 #13449] : :nice_delta: 10
[-] I 10:56:41.488363 #13449] : :parent_time_threshold: 180
[-] I 10:56:41.488394 #13449] : :poll: 3
[-] I 10:56:41.488425 #13449] : :poll_escalate_max: 30
[-] I 10:56:41.488455 #13449] : :poll_method: :normal
[-] I 10:56:41.488484 #13449] : :restart_interval: 0
[-] I 10:56:41.488515 #13449] : :starting_timeout: 600
[-] I 10:56:41.488973 #13449] : :cpu_usage_threshold: 100
[-] I 10:56:41.489008 #13449] : :dequeue_method: :drb
[-] I 10:56:41.489039 #13449] : :queue_timeout: 600
[-] I 10:56:41.489062 #13449] : ---
[-] I 10:56:41.489448 #13449] : :guid: 1af9dab2-5315-11e5-8e34-b8e856479e14
[-] I 10:56:41.490534 #13448] : MIQ(Vmdb::Loggers.apply_config) Log level for development.log has been changed to [INFO]
[-] I 10:56:41.508499 #13448] : MIQ(GenericWorker#sync_config) ID [2], PID [13448], GUID [1af71d86-5315-11e5-8e34-b8e856479e14], Zone [default], Active Roles [automate,database_operations,database_owner,ems_inventory,ems_operations,event,reporting,scheduler,smartstate,user_interface,web_services], Assigned Roles [automate,database_operations,database_owner,ems_inventory,ems_operations,event,reporting,scheduler,smartstate,user_interface,web_services], Configuration:
[-] I 10:56:41.509398 #13448] : :count: 2
[-] I 10:56:41.509450 #13448] : :gc_interval: 900
[-] I 10:56:41.509536 #13448] : :heartbeat_freq: 60
[-] I 10:56:41.509619 #13448] : :heartbeat_timeout: 120
[-] I 10:56:41.510046 #13448] : :memory_threshold: 419430400
[-] I 10:56:41.510114 #13448] : :nice_delta: 10
[-] I 10:56:41.510174 #13448] : :parent_time_threshold: 180
[-] I 10:56:41.510233 #13448] : :poll: 3
[-] I 10:56:41.510292 #13448] : :poll_escalate_max: 30
[-] I 10:56:41.510350 #13448] : :poll_method: :normal
[-] I 10:56:41.510408 #13448] : :restart_interval: 0
[-] I 10:56:41.510466 #13448] : :starting_timeout: 600
[-] I 10:56:41.510525 #13448] : :cpu_usage_threshold: 100
[-] I 10:56:41.510586 #13448] : :dequeue_method: :drb
[-] I 10:56:41.510645 #13448] : :queue_timeout: 600
[-] I 10:56:41.510717 #13448] : ---
[-] I 10:56:41.511090 #13448] : :guid: 1af71d86-5315-11e5-8e34-b8e856479e14
[-] I 10:56:41.846822 #13449] : GenericWorker started. ID [3], PID [13449], GUID [1af9dab2-5315-11e5-8e34-b8e856479e14], Zone [default], Role [automate,database_operations,database_owner,ems_inventory,ems_operations,event,reporting,scheduler,smartstate,user_interface,web_services]
[-] I 10:56:41.846907 #13449] : MIQ(GenericWorker#do_wait_for_worker_monitor) MIQ(GenericWorker) Checking that worker monitor has started before doing work
[-] I 10:56:41.850464 #13449] : MIQ(GenericWorker#worker_monitor_drb) MIQ(GenericWorker) Initializing DRb Connection to MiqServer with ID=[3], NAME=[EVM], PID=[13413], GUID=[c69aab4c-4755-11e5-8436-b8e856479e14] DRb URI=[druby://127.0.0.1]
[-] I 10:56:41.879495 #13448] : GenericWorker started. ID [2], PID [13448], GUID [1af71d86-5315-11e5-8e34-b8e856479e14], Zone [default], Role [automate,database_operations,database_owner,ems_inventory,ems_operations,event,reporting,scheduler,smartstate,user_interface,web_services]
[-] I 10:56:41.879583 #13448] : MIQ(GenericWorker#do_wait_for_worker_monitor) MIQ(GenericWorker) Checking that worker monitor has started before doing work
[-] I 10:56:41.883593 #13448] : MIQ(GenericWorker#worker_monitor_drb) MIQ(GenericWorker) Initializing DRb Connection to MiqServer with ID=[3], NAME=[EVM], PID=[13413], GUID=[c69aab4c-4755-11e5-8436-b8e856479e14] DRb URI=[druby://127.0.0.1]
[-] I 10:56:42.134574 #13453] : MIQ(Vmdb::Loggers.apply_config) Log level for development.log has been changed to [INFO]
[-] I 10:56:42.138626 #13452] : MIQ(Vmdb::Loggers.apply_config) Log level for development.log has been changed to [INFO]
[-] I 10:56:42.146301 #13453] : MIQ(PriorityWorker#sync_config) ID [5], PID [13453], GUID [1b1e67ba-5315-11e5-8e34-b8e856479e14], Zone [default], Active Roles [automate,database_operations,database_owner,ems_inventory,ems_operations,event,reporting,scheduler,smartstate,user_interface,web_services], Assigned Roles [automate,database_operations,database_owner,ems_inventory,ems_operations,event,reporting,scheduler,smartstate,user_interface,web_services], Configuration:
[-] I 10:56:42.147771 #13453] : :count: 2
[-] I 10:56:42.147833 #13453] : :gc_interval: 900
[-] I 10:56:42.147871 #13453] : :heartbeat_freq: 60
[-] I 10:56:42.147934 #13453] : :heartbeat_timeout: 120
[-] I 10:56:42.147988 #13453] : :memory_threshold: 419430400
[-] I 10:56:42.148023 #13453] : :nice_delta: 1
[-] I 10:56:42.148057 #13453] : :parent_time_threshold: 180
[-] I 10:56:42.148086 #13453] : :poll: 1
[-] I 10:56:42.148112 #13453] : :poll_escalate_max: 30
[-] I 10:56:42.148141 #13453] : :poll_method: :normal
[-] I 10:56:42.148169 #13453] : :restart_interval: 0
[-] I 10:56:42.148167 #13452] : MIQ(PriorityWorker#sync_config) ID [4], PID [13452], GUID [1b1b246a-5315-11e5-8e34-b8e856479e14], Zone [default], Active Roles [automate,database_operations,database_owner,ems_inventory,ems_operations,event,reporting,scheduler,smartstate,user_interface,web_services], Assigned Roles [automate,database_operations,database_owner,ems_inventory,ems_operations,event,reporting,scheduler,smartstate,user_interface,web_services], Configuration:
[-] I 10:56:42.148222 #13453] : :starting_timeout: 600
[-] I 10:56:42.148285 #13453] : :cpu_usage_threshold: 100
[-] I 10:56:42.148333 #13453] : :dequeue_method: :drb
[-] I 10:56:42.148362 #13453] : :queue_timeout: 600
[-] I 10:56:42.148417 #13453] : ---
[-] I 10:56:42.148814 #13453] : :guid: 1b1e67ba-5315-11e5-8e34-b8e856479e14
[-] I 10:56:42.149293 #13452] : :count: 2
[-] I 10:56:42.149344 #13452] : :gc_interval: 900
[-] I 10:56:42.149376 #13452] : :heartbeat_freq: 60
[-] I 10:56:42.149407 #13452] : :heartbeat_timeout: 120
[-] I 10:56:42.149435 #13452] : :memory_threshold: 419430400
[-] I 10:56:42.149463 #13452] : :nice_delta: 1
[-] I 10:56:42.149490 #13452] : :parent_time_threshold: 180
[-] I 10:56:42.149517 #13452] : :poll: 1
[-] I 10:56:42.149543 #13452] : :poll_escalate_max: 30
[-] I 10:56:42.149569 #13452] : :poll_method: :normal
[-] I 10:56:42.149594 #13452] : :restart_interval: 0
[-] I 10:56:42.149880 #13452] : :starting_timeout: 600
[-] I 10:56:42.149915 #13452] : :cpu_usage_threshold: 100
[-] I 10:56:42.149948 #13452] : :dequeue_method: :drb
[-] I 10:56:42.149976 #13452] : :queue_timeout: 600
[-] I 10:56:42.150003 #13452] : ---
[-] I 10:56:42.150315 #13452] : :guid: 1b1b246a-5315-11e5-8e34-b8e856479e14
[-] I 10:56:42.440389 #13453] : PriorityWorker started. ID [5], PID [13453], GUID [1b1e67ba-5315-11e5-8e34-b8e856479e14], Zone [default], Role [automate,database_operations,database_owner,ems_inventory,ems_operations,event,reporting,scheduler,smartstate,user_interface,web_services]
[-] I 10:56:42.442565 #13453] : MIQ(PriorityWorker#worker_monitor_drb) MIQ(PriorityWorker) Initializing DRb Connection to MiqServer with ID=[3], NAME=[EVM], PID=[13413], GUID=[c69aab4c-4755-11e5-8436-b8e856479e14] DRb URI=[druby://127.0.0.1]
[-] I 10:56:42.448615 #13452] : PriorityWorker started. ID [4], PID [13452], GUID [1b1b246a-5315-11e5-8e34-b8e856479e14], Zone [default], Role [automate,database_operations,database_owner,ems_inventory,ems_operations,event,reporting,scheduler,smartstate,user_interface,web_services]
[-] I 10:56:42.450766 #13452] : MIQ(PriorityWorker#worker_monitor_drb) MIQ(PriorityWorker) Initializing DRb Connection to MiqServer with ID=[3], NAME=[EVM], PID=[13413], GUID=[c69aab4c-4755-11e5-8436-b8e856479e14] DRb URI=[druby://127.0.0.1]
[-] I 10:56:42.720324 #13457] : MIQ(Vmdb::Loggers.apply_config) Log level for development.log has been changed to [INFO]
[-] I 10:56:42.724599 #13457] : MIQ(ReportingWorker#sync_config) ID [7], PID [13457], GUID [1b4f11f8-5315-11e5-8e34-b8e856479e14], Zone [default], Active Roles [automate,database_operations,database_owner,ems_inventory,ems_operations,event,reporting,scheduler,smartstate,user_interface,web_services], Assigned Roles [automate,database_operations,database_owner,ems_inventory,ems_operations,event,reporting,scheduler,smartstate,user_interface,web_services], Configuration:
[-] I 10:56:42.725461 #13457] : :count: 2
[-] I 10:56:42.725514 #13457] : :gc_interval: 900
[-] I 10:56:42.725578 #13457] : :heartbeat_freq: 60
[-] I 10:56:42.725608 #13457] : :heartbeat_timeout: 120
[-] I 10:56:42.725637 #13457] : :memory_threshold: 419430400
[-] I 10:56:42.725665 #13457] : :nice_delta: 7
[-] I 10:56:42.725694 #13457] : :parent_time_threshold: 180
[-] I 10:56:42.725722 #13457] : :poll: 3
[-] I 10:56:42.725750 #13457] : :poll_escalate_max: 30
[-] I 10:56:42.725778 #13457] : :poll_method: :normal
[-] I 10:56:42.725805 #13457] : :restart_interval: 0
[-] I 10:56:42.725868 #13457] : :starting_timeout: 600
[-] I 10:56:42.725896 #13457] : :cpu_usage_threshold: 100
[-] I 10:56:42.725923 #13457] : :dequeue_method: :drb
[-] I 10:56:42.725949 #13457] : :queue_timeout: 600
[-] I 10:56:42.725974 #13457] : ---
[-] I 10:56:42.726302 #13457] : :guid: 1b4f11f8-5315-11e5-8e34-b8e856479e14
[-] I 10:56:42.737892 #13456] : MIQ(Vmdb::Loggers.apply_config) Log level for development.log has been changed to [INFO]
[-] I 10:56:42.742204 #13456] : MIQ(ReportingWorker#sync_config) ID [6], PID [13456], GUID [1b49f6aa-5315-11e5-8e34-b8e856479e14], Zone [default], Active Roles [automate,database_operations,database_owner,ems_inventory,ems_operations,event,reporting,scheduler,smartstate,user_interface,web_services], Assigned Roles [automate,database_operations,database_owner,ems_inventory,ems_operations,event,reporting,scheduler,smartstate,user_interface,web_services], Configuration:
[-] I 10:56:42.743212 #13456] : :count: 2
[-] I 10:56:42.743264 #13456] : :gc_interval: 900
[-] I 10:56:42.743320 #13456] : :heartbeat_freq: 60
[-] I 10:56:42.743396 #13456] : :heartbeat_timeout: 120
[-] I 10:56:42.743475 #13456] : :memory_threshold: 419430400
[-] I 10:56:42.743515 #13456] : :nice_delta: 7
[-] I 10:56:42.743563 #13456] : :parent_time_threshold: 180
[-] I 10:56:42.743610 #13456] : :poll: 3
[-] I 10:56:42.743702 #13456] : :poll_escalate_max: 30
[-] I 10:56:42.743750 #13456] : :poll_method: :normal
[-] I 10:56:42.743783 #13456] : :restart_interval: 0
[-] I 10:56:42.743858 #13456] : :starting_timeout: 600
[-] I 10:56:42.743887 #13456] : :cpu_usage_threshold: 100
[-] I 10:56:42.743911 #13456] : :dequeue_method: :drb
[-] I 10:56:42.743937 #13456] : :queue_timeout: 600
[-] I 10:56:42.743965 #13456] : ---
[-] I 10:56:42.744350 #13456] : :guid: 1b49f6aa-5315-11e5-8e34-b8e856479e14
[-] I 10:56:42.922005 #13457] : ReportingWorker started. ID [7], PID [13457], GUID [1b4f11f8-5315-11e5-8e34-b8e856479e14], Zone [default], Role [automate,database_operations,database_owner,ems_inventory,ems_operations,event,reporting,scheduler,smartstate,user_interface,web_services]
[-] I 10:56:42.922131 #13457] : MIQ(ReportingWorker#do_wait_for_worker_monitor) MIQ(ReportingWorker) Checking that worker monitor has started before doing work
[-] I 10:56:42.930937 #13457] : MIQ(ReportingWorker#worker_monitor_drb) MIQ(ReportingWorker) Initializing DRb Connection to MiqServer with ID=[3], NAME=[EVM], PID=[13413], GUID=[c69aab4c-4755-11e5-8436-b8e856479e14] DRb URI=[druby://127.0.0.1]
[-] I 10:56:42.943231 #13456] : ReportingWorker started. ID [6], PID [13456], GUID [1b49f6aa-5315-11e5-8e34-b8e856479e14], Zone [default], Role [automate,database_operations,database_owner,ems_inventory,ems_operations,event,reporting,scheduler,smartstate,user_interface,web_services]
[-] I 10:56:42.943311 #13456] : MIQ(ReportingWorker#do_wait_for_worker_monitor) MIQ(ReportingWorker) Checking that worker monitor has started before doing work
[-] I 10:56:42.946632 #13456] : MIQ(ReportingWorker#worker_monitor_drb) MIQ(ReportingWorker) Initializing DRb Connection to MiqServer with ID=[3], NAME=[EVM], PID=[13413], GUID=[c69aab4c-4755-11e5-8436-b8e856479e14] DRb URI=[druby://127.0.0.1]
[-] I 10:56:43.036014 #13462] : MIQ(Vmdb::Loggers.apply_config) Log level for development.log has been changed to [INFO]
[-] I 10:56:43.039433 #13462] : MIQ(UiWorker#sync_config) ID [9], PID [13462], GUID [1bc08720-5315-11e5-8e34-b8e856479e14], Zone [default], Active Roles [automate,database_operations,database_owner,ems_inventory,ems_operations,event,reporting,scheduler,smartstate,user_interface,web_services], Assigned Roles [automate,database_operations,database_owner,ems_inventory,ems_operations,event,reporting,scheduler,smartstate,user_interface,web_services], Configuration:
[-] I 10:56:43.040021 #13462] : :count: 1
[-] I 10:56:43.040060 #13462] : :gc_interval: 900
[-] I 10:56:43.040157 #13462] : :heartbeat_freq: 60
[-] I 10:56:43.040220 #13462] : :heartbeat_timeout: 120
[-] I 10:56:43.040256 #13462] : :memory_threshold: 1073741824
[-] I 10:56:43.040321 #13462] : :nice_delta: 1
[-] I 10:56:43.040367 #13462] : :parent_time_threshold: 180
[-] I 10:56:43.040398 #13462] : :poll: 60
[-] I 10:56:43.040421 #13462] : :poll_escalate_max: 30
[-] I 10:56:43.040452 #13462] : :poll_method: :normal
[-] I 10:56:43.040483 #13462] : :restart_interval: 0
[-] I 10:56:43.040516 #13462] : :starting_timeout: 600
[-] I 10:56:43.040544 #13462] : :connection_pool_size: 5
[-] I 10:56:43.040573 #13462] : ---
[-] I 10:56:43.040851 #13462] : :guid: 1bc08720-5315-11e5-8e34-b8e856479e14
[-] I 10:56:43.068118 #13460] : MIQ(Vmdb::Loggers.apply_config) Log level for development.log has been changed to [INFO]
[-] I 10:56:43.073917 #13460] : MIQ(ScheduleWorker#sync_config) ID [8], PID [13460], GUID [1b8c860a-5315-11e5-8e34-b8e856479e14], Zone [default], Active Roles [automate,database_operations,database_owner,ems_inventory,ems_operations,event,reporting,scheduler,smartstate,user_interface,web_services], Assigned Roles [automate,database_operations,database_owner,ems_inventory,ems_operations,event,reporting,scheduler,smartstate,user_interface,web_services], Configuration:
[-] I 10:56:43.075483 #13460] : :count: 1
[-] I 10:56:43.075550 #13460] : :gc_interval: 900
[-] I 10:56:43.075585 #13460] : :heartbeat_freq: 60
[-] I 10:56:43.075616 #13460] : :heartbeat_timeout: 120
[-] I 10:56:43.075643 #13460] : :memory_threshold: 262144000
[-] I 10:56:43.075674 #13460] : :nice_delta: 3
[-] I 10:56:43.075700 #13460] : :parent_time_threshold: 180
[-] I 10:56:43.075785 #13460] : :poll: 15
[-] I 10:56:43.075811 #13460] : :poll_escalate_max: 30
[-] I 10:56:43.075836 #13460] : :poll_method: :normal
[-] I 10:56:43.075862 #13460] : :restart_interval: 0
[-] I 10:56:43.075886 #13460] : :starting_timeout: 600
[-] I 10:56:43.075911 #13460] : :authentication_check_interval: 86400
[-] I 10:56:43.075936 #13460] : :db_diagnostics_interval: 1800
[-] I 10:56:43.075961 #13460] : :ems_events_purge_interval: 86400
[-] I 10:56:43.075986 #13460] : :evm_snapshot_delete_delay_for_job_not_found: 3600
[-] I 10:56:43.076012 #13460] : :evm_snapshot_interval: 3600
[-] I 10:56:43.076047 #13460] : :job_proxy_dispatcher_interval: 15
[-] I 10:56:43.076102 #13460] : :job_proxy_dispatcher_stale_message_check_interval: 60
[-] I 10:56:43.076128 #13460] : :job_proxy_dispatcher_stale_message_timeout: 120
[-] I 10:56:43.076221 #13460] : :job_timeout_interval: 60
[-] I 10:56:43.076272 #13460] : :log_active_configuration_interval: 86400
[-] I 10:56:43.076313 #13460] : :log_database_statistics_interval: 86400
[-] I 10:56:43.076352 #13460] : :orchestration_stack_retired_interval: 600
[-] I 10:56:43.076412 #13460] : :performance_collection_interval: 180
[-] I 10:56:43.076454 #13460] : :performance_collection_start_delay: 300
[-] I 10:56:43.076492 #13460] : :performance_realtime_purging_interval: 900
[-] I 10:56:43.076531 #13460] : :performance_realtime_purging_start_delay: 300
[-] I 10:56:43.076569 #13460] : :performance_rollup_purging_interval: 14400
[-] I 10:56:43.076607 #13460] : :performance_rollup_purging_start_delay: 300
[-] I 10:56:43.076644 #13460] : :policy_events_purge_interval: 86400
[-] I 10:56:43.076681 #13460] : :server_log_stats_interval: 300
[-] I 10:56:43.076743 #13460] : :server_stats_interval: 60
[-] I 10:56:43.076779 #13460] : :service_retired_interval: 600
[-] I 10:56:43.076815 #13460] : :session_timeout_interval: 30
[-] I 10:56:43.076851 #13460] : :storage_file_collection_interval: 86400
[-] I 10:56:43.076888 #13460] : :storage_file_collection_time_utc: 21600
[-] I 10:56:43.076925 #13460] : :vm_retired_interval: 600
[-] I 10:56:43.076961 #13460] : :vm_scan_interval: 600
[-] I 10:56:43.076995 #13460] : ---
[-] I 10:56:43.077270 #13460] : :guid: 1b8c860a-5315-11e5-8e34-b8e856479e14
[-] I 10:56:43.214954 #13462] : UiWorker started. ID [9], PID [13462], GUID [1bc08720-5315-11e5-8e34-b8e856479e14], Zone [default], Role [automate,database_operations,database_owner,ems_inventory,ems_operations,event,reporting,scheduler,smartstate,user_interface,web_services]
[-] I 10:56:43.217193 #13462] : MIQ(Vmdb::Initializer.init) - Init complete
[-] I 10:56:43.222428 #13462] : MIQ(UiWorker#worker_monitor_drb) MIQ(UiWorker) Initializing DRb Connection to MiqServer with ID=[3], NAME=[EVM], PID=[13413], GUID=[c69aab4c-4755-11e5-8436-b8e856479e14] DRb URI=[druby://127.0.0.1]
[-] I 10:56:43.264130 #13460] : ScheduleWorker started. ID [8], PID [13460], GUID [1b8c860a-5315-11e5-8e34-b8e856479e14], Zone [default], Role [automate,database_operations,database_owner,ems_inventory,ems_operations,event,reporting,scheduler,smartstate,user_interface,web_services]
[-] I 10:56:43.264223 #13460] : MIQ(ScheduleWorker#do_wait_for_worker_monitor) MIQ(ScheduleWorker) Checking that worker monitor has started before doing work
[-] I 10:56:43.267684 #13460] : MIQ(ScheduleWorker#worker_monitor_drb) MIQ(ScheduleWorker) Initializing DRb Connection to MiqServer with ID=[3], NAME=[EVM], PID=[13413], GUID=[c69aab4c-4755-11e5-8436-b8e856479e14] DRb URI=[druby://127.0.0.1]
[-] I 10:56:43.395428 #13464] : MIQ(Vmdb::Loggers.apply_config) Log level for development.log has been changed to [INFO]
[-] I 10:56:43.398554 #13464] : MIQ(WebServiceWorker#sync_config) ID [10], PID [13464], GUID [1c1ac9c4-5315-11e5-8e34-b8e856479e14], Zone [default], Active Roles [automate,database_operations,database_owner,ems_inventory,ems_operations,event,reporting,scheduler,smartstate,user_interface,web_services], Assigned Roles [automate,database_operations,database_owner,ems_inventory,ems_operations,event,reporting,scheduler,smartstate,user_interface,web_services], Configuration:
[-] I 10:56:43.399224 #13464] : :count: 1
[-] I 10:56:43.399288 #13464] : :gc_interval: 900
[-] I 10:56:43.399335 #13464] : :heartbeat_freq: 60
[-] I 10:56:43.399381 #13464] : :heartbeat_timeout: 120
[-] I 10:56:43.399435 #13464] : :memory_threshold: 1073741824
[-] I 10:56:43.399473 #13464] : :nice_delta: 1
[-] I 10:56:43.399547 #13464] : :parent_time_threshold: 180
[-] I 10:56:43.399589 #13464] : :poll: 60
[-] I 10:56:43.399622 #13464] : :poll_escalate_max: 30
[-] I 10:56:43.399654 #13464] : :poll_method: :normal
[-] I 10:56:43.399681 #13464] : :restart_interval: 0
[-] I 10:56:43.399706 #13464] : :starting_timeout: 600
[-] I 10:56:43.399755 #13464] : :connection_pool_size: 5
[-] I 10:56:43.399783 #13464] : ---
[-] I 10:56:43.400056 #13464] : :guid: 1c1ac9c4-5315-11e5-8e34-b8e856479e14
[-] I 10:56:43.543246 #13464] : WebServiceWorker started. ID [10], PID [13464], GUID [1c1ac9c4-5315-11e5-8e34-b8e856479e14], Zone [default], Role [automate,database_operations,database_owner,ems_inventory,ems_operations,event,reporting,scheduler,smartstate,user_interface,web_services]
[-] I 10:56:43.544583 #13464] : MIQ(Vmdb::Initializer.init) - Init complete
[-] I 10:56:43.555553 #13464] : MIQ(WebServiceWorker#worker_monitor_drb) MIQ(WebServiceWorker) Initializing DRb Connection to MiqServer with ID=[3], NAME=[EVM], PID=[13413], GUID=[c69aab4c-4755-11e5-8436-b8e856479e14] DRb URI=[druby://127.0.0.1]
[-] I 10:56:43.787157 #13466] : MIQ(Vmdb::Loggers.apply_config) Log level for development.log has been changed to [INFO]
[-] I 10:56:43.790381 #13466] : MIQ(AutomateWorker#sync_config) ID [11], PID [13466], GUID [1c5a0e36-5315-11e5-8e34-b8e856479e14], Zone [default], Active Roles [automate,database_operations,database_owner,ems_inventory,ems_operations,event,reporting,scheduler,smartstate,user_interface,web_services], Assigned Roles [automate,database_operations,database_owner,ems_inventory,ems_operations,event,reporting,scheduler,smartstate,user_interface,web_services], Configuration:
[-] I 10:56:43.791024 #13466] : :count: 2
[-] I 10:56:43.791060 #13466] : :gc_interval: 900
[-] I 10:56:43.791089 #13466] : :heartbeat_freq: 60
[-] I 10:56:43.791115 #13466] : :heartbeat_timeout: 120
[-] I 10:56:43.791142 #13466] : :memory_threshold: 419430400
[-] I 10:56:43.791169 #13466] : :nice_delta: 10
[-] I 10:56:43.791221 #13466] : :parent_time_threshold: 180
[-] I 10:56:43.791269 #13466] : :poll: 3
[-] I 10:56:43.791313 #13466] : :poll_escalate_max: 30
[-] I 10:56:43.791353 #13466] : :poll_method: :normal
[-] I 10:56:43.791379 #13466] : :restart_interval: 0
[-] I 10:56:43.791430 #13466] : :starting_timeout: 600
[-] I 10:56:43.791474 #13466] : :cpu_usage_threshold: 100
[-] I 10:56:43.791507 #13466] : :dequeue_method: :drb
[-] I 10:56:43.791535 #13466] : :queue_timeout: 600
[-] I 10:56:43.791578 #13466] : ---
[-] I 10:56:43.791869 #13466] : :guid: 1c5a0e36-5315-11e5-8e34-b8e856479e14
[-] I 10:56:43.803342 #13467] : MIQ(Vmdb::Loggers.apply_config) Log level for development.log has been changed to [INFO]
[-] I 10:56:43.807641 #13467] : MIQ(AutomateWorker#sync_config) ID [12], PID [13467], GUID [1c5e7804-5315-11e5-8e34-b8e856479e14], Zone [default], Active Roles [automate,database_operations,database_owner,ems_inventory,ems_operations,event,reporting,scheduler,smartstate,user_interface,web_services], Assigned Roles [automate,database_operations,database_owner,ems_inventory,ems_operations,event,reporting,scheduler,smartstate,user_interface,web_services], Configuration:
[-] I 10:56:43.808621 #13467] : :count: 2
[-] I 10:56:43.808915 #13467] : :gc_interval: 900
[-] I 10:56:43.808948 #13467] : :heartbeat_freq: 60
[-] I 10:56:43.808978 #13467] : :heartbeat_timeout: 120
[-] I 10:56:43.809006 #13467] : :memory_threshold: 419430400
[-] I 10:56:43.809031 #13467] : :nice_delta: 10
[-] I 10:56:43.809056 #13467] : :parent_time_threshold: 180
[-] I 10:56:43.809080 #13467] : :poll: 3
[-] I 10:56:43.809104 #13467] : :poll_escalate_max: 30
[-] I 10:56:43.809129 #13467] : :poll_method: :normal
[-] I 10:56:43.809153 #13467] : :restart_interval: 0
[-] I 10:56:43.809177 #13467] : :starting_timeout: 600
[-] I 10:56:43.809200 #13467] : :cpu_usage_threshold: 100
[-] I 10:56:43.809233 #13467] : :dequeue_method: :drb
[-] I 10:56:43.809264 #13467] : :queue_timeout: 600
[-] I 10:56:43.809286 #13467] : ---
[-] I 10:56:43.809556 #13467] : :guid: 1c5e7804-5315-11e5-8e34-b8e856479e14
[-] I 10:56:43.932611 #13466] : AutomateWorker started. ID [11], PID [13466], GUID [1c5a0e36-5315-11e5-8e34-b8e856479e14], Zone [default], Role [automate,database_operations,database_owner,ems_inventory,ems_operations,event,reporting,scheduler,smartstate,user_interface,web_services]
[-] I 10:56:43.932673 #13466] : MIQ(AutomateWorker#do_wait_for_worker_monitor) MIQ(AutomateWorker) Checking that worker monitor has started before doing work
[-] I 10:56:43.934828 #13466] : MIQ(AutomateWorker#worker_monitor_drb) MIQ(AutomateWorker) Initializing DRb Connection to MiqServer with ID=[3], NAME=[EVM], PID=[13413], GUID=[c69aab4c-4755-11e5-8436-b8e856479e14] DRb URI=[druby://127.0.0.1]
[-] I 10:56:43.970367 #13467] : AutomateWorker started. ID [12], PID [13467], GUID [1c5e7804-5315-11e5-8e34-b8e856479e14], Zone [default], Role [automate,database_operations,database_owner,ems_inventory,ems_operations,event,reporting,scheduler,smartstate,user_interface,web_services]
[-] I 10:56:43.970428 #13467] : MIQ(AutomateWorker#do_wait_for_worker_monitor) MIQ(AutomateWorker) Checking that worker monitor has started before doing work
[-] I 10:56:43.973351 #13467] : MIQ(AutomateWorker#worker_monitor_drb) MIQ(AutomateWorker) Initializing DRb Connection to MiqServer with ID=[3], NAME=[EVM], PID=[13413], GUID=[c69aab4c-4755-11e5-8436-b8e856479e14] DRb URI=[druby://127.0.0.1]
[-] I 10:56:44.035727 #13413] : MIQ(MiqServer#wait_for_started_workers) All workers have been started
[-] I 10:56:44.040384 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:56:44 UTC]...
[-] I 10:56:44.043794 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:56:44 UTC]...Complete
[-] E 10:56:44.090106 #13413] : MIQ(MiqServer#monitor) comparison of Array with Array failed
[-] E 10:56:44.090242 #13413] : [ArgumentError]: comparison of Array with Array failed Method:[rescue in monitor]
[-] E 10:56:44.090305 #13413] : /Users/kbrock/.gem/ruby/2.2.2/gems/activerecord-4.2.3/lib/active_record/relation/delegation.rb:132:in `sort_by'
/Users/kbrock/.gem/ruby/2.2.2/gems/activerecord-4.2.3/lib/active_record/relation/delegation.rb:132:in `public_send'
/Users/kbrock/.gem/ruby/2.2.2/gems/activerecord-4.2.3/lib/active_record/relation/delegation.rb:132:in `method_missing'
/Users/kbrock/.gem/ruby/2.2.2/gems/activerecord-4.2.3/lib/active_record/relation/delegation.rb:99:in `method_missing'
/Users/kbrock/src/manageiq/app/models/miq_server.rb:298:in `log_active_servers'
/Users/kbrock/src/manageiq/app/models/miq_server.rb:363:in `block in monitor'
/Users/kbrock/src/manageiq/gems/pending/util/extensions/miq-benchmark.rb:12:in `realtime_store'
/Users/kbrock/src/manageiq/gems/pending/util/extensions/miq-benchmark.rb:31:in `realtime_block'
/Users/kbrock/src/manageiq/app/models/miq_server.rb:363:in `monitor'
/Users/kbrock/src/manageiq/app/models/miq_server.rb:385:in `block (2 levels) in monitor_loop'
/Users/kbrock/src/manageiq/gems/pending/util/extensions/miq-benchmark.rb:12:in `realtime_store'
/Users/kbrock/src/manageiq/gems/pending/util/extensions/miq-benchmark.rb:31:in `realtime_block'
/Users/kbrock/src/manageiq/app/models/miq_server.rb:385:in `block in monitor_loop'
/Users/kbrock/src/manageiq/app/models/miq_server.rb:384:in `loop'
/Users/kbrock/src/manageiq/app/models/miq_server.rb:384:in `monitor_loop'
/Users/kbrock/src/manageiq/app/models/miq_server.rb:274:in `start'
/Users/kbrock/src/manageiq/lib/workers/evm_server.rb:62:in `start'
/Users/kbrock/src/manageiq/lib/workers/evm_server.rb:81:in `start'
/Users/kbrock/src/manageiq/lib/workers/bin/evm_server.rb:2:in `<top (required)>'
/Users/kbrock/.gem/ruby/2.2.2/gems/railties-4.2.3/lib/rails/commands/runner.rb:60:in `load'
/Users/kbrock/.gem/ruby/2.2.2/gems/railties-4.2.3/lib/rails/commands/runner.rb:60:in `<top (required)>'
/Users/kbrock/.gem/ruby/2.2.2/gems/railties-4.2.3/lib/rails/commands/commands_tasks.rb:123:in `require'
/Users/kbrock/.gem/ruby/2.2.2/gems/railties-4.2.3/lib/rails/commands/commands_tasks.rb:123:in `require_command!'
/Users/kbrock/.gem/ruby/2.2.2/gems/railties-4.2.3/lib/rails/commands/commands_tasks.rb:90:in `runner'
/Users/kbrock/.gem/ruby/2.2.2/gems/railties-4.2.3/lib/rails/commands/commands_tasks.rb:39:in `run_command!'
/Users/kbrock/.gem/ruby/2.2.2/gems/railties-4.2.3/lib/rails/commands.rb:17:in `<top (required)>'
/Users/kbrock/src/manageiq/bin/rails:4:in `require'
/Users/kbrock/src/manageiq/bin/rails:4:in `<main>'
[-] I 10:56:44.090330 #13413] : MIQ(MiqServer#monitor) Reconnecting to database after error...
[-] I 10:56:44.101263 #13413] : MIQ(MiqServer#monitor) Reconnecting to database after error...Successful
[-] I 10:56:44.298974 #13446] : MIQ(EventHandler#do_wait_for_worker_monitor) MIQ(EventHandler) Starting work since worker monitor has started
[-] I 10:56:44.859441 #13449] : MIQ(GenericWorker#do_wait_for_worker_monitor) MIQ(GenericWorker) Starting work since worker monitor has started
[-] I 10:56:44.892111 #13448] : MIQ(GenericWorker#do_wait_for_worker_monitor) MIQ(GenericWorker) Starting work since worker monitor has started
[-] I 10:56:45.941010 #13457] : MIQ(ReportingWorker#do_wait_for_worker_monitor) MIQ(ReportingWorker) Starting work since worker monitor has started
[-] I 10:56:45.953973 #13456] : MIQ(ReportingWorker#do_wait_for_worker_monitor) MIQ(ReportingWorker) Starting work since worker monitor has started
[-] I 10:56:46.278699 #13460] : MIQ(ScheduleWorker#do_wait_for_worker_monitor) MIQ(ScheduleWorker) Starting work since worker monitor has started
[-] I 10:56:46.291136 #13460] : MIQ(ScheduleWorker#schedules_for_database_operations_role) database_metrics_collection_schedule: 1 * * * *
[-] I 10:56:46.541225 #13460] : MIQ(ScheduleWorker#schedules_for_database_operations_role) database_metrics_daily_rollup_schedule: 23 0 * * *
[-] I 10:56:46.557905 #13460] : MIQ(ScheduleWorker#schedules_for_database_operations_role) database_metrics_purge_schedule: 50 * * * *
[-] I 10:56:46.855680 #13460] : MIQ(ScheduleWorker#reload_schedules) Reloading schedule: [Guest OS Information] with id: [1]
[-] I 10:56:46.857442 #13460] : MIQ(MiqSchedule#next_interval_time) sch_start_time: 2015-07-22 00:00:00 UTC
[-] I 10:56:46.857681 #13460] : MIQ(MiqSchedule#next_interval_time) next_time: 2015-09-05 00:00:00 UTC
[-] I 10:56:46.858307 #13460] : MIQ(MiqSchedule#rufus_schedule_opts) Schedule [Guest OS Information] scheduled to run at 2015-09-05 00:00:00 UTC with interval 86400
[-] I 10:56:46.858471 #13460] : MIQ(ScheduleWorker#reload_schedules) Reloading schedule: [Hosts - Summary by Version] with id: [2]
[-] I 10:56:46.859318 #13460] : MIQ(MiqSchedule#next_interval_time) sch_start_time: 2015-07-22 00:00:00 UTC
[-] I 10:56:46.859493 #13460] : MIQ(MiqSchedule#next_interval_time) next_time: 2015-09-05 00:00:00 UTC
[-] I 10:56:46.860077 #13460] : MIQ(MiqSchedule#rufus_schedule_opts) Schedule [Hosts - Summary by Version] scheduled to run at 2015-09-05 00:00:00 UTC with interval 86400
[-] I 10:56:46.860208 #13460] : MIQ(ScheduleWorker#reload_schedules) Reloading schedule: [Vendor and Guest OS Chart] with id: [3]
[-] I 10:56:46.861072 #13460] : MIQ(MiqSchedule#next_interval_time) sch_start_time: 2015-07-22 00:00:00 UTC
[-] I 10:56:46.861244 #13460] : MIQ(MiqSchedule#next_interval_time) next_time: 2015-09-05 00:00:00 UTC
[-] I 10:56:46.861885 #13460] : MIQ(MiqSchedule#rufus_schedule_opts) Schedule [Vendor and Guest OS Chart] scheduled to run at 2015-09-05 00:00:00 UTC with interval 86400
[-] I 10:56:46.861997 #13460] : MIQ(ScheduleWorker#reload_schedules) Reloading schedule: [Virtual Infrastructure Platforms] with id: [4]
[-] I 10:56:46.862864 #13460] : MIQ(MiqSchedule#next_interval_time) sch_start_time: 2015-07-22 00:00:00 UTC
[-] I 10:56:46.863051 #13460] : MIQ(MiqSchedule#next_interval_time) next_time: 2015-09-05 00:00:00 UTC
[-] I 10:56:46.863728 #13460] : MIQ(MiqSchedule#rufus_schedule_opts) Schedule [Virtual Infrastructure Platforms] scheduled to run at 2015-09-05 00:00:00 UTC with interval 86400
[-] I 10:56:46.863874 #13460] : MIQ(ScheduleWorker#reload_schedules) Reloading schedule: [Top CPU Consumers (weekly)] with id: [5]
[-] I 10:56:46.864953 #13460] : MIQ(MiqSchedule#next_interval_time) sch_start_time: 2015-07-22 00:00:00 UTC
[-] I 10:56:46.865136 #13460] : MIQ(MiqSchedule#next_interval_time) next_time: 2015-09-05 00:00:00 UTC
[-] I 10:56:46.865742 #13460] : MIQ(MiqSchedule#rufus_schedule_opts) Schedule [Top CPU Consumers (weekly)] scheduled to run at 2015-09-05 00:00:00 UTC with interval 86400
[-] I 10:56:46.865871 #13460] : MIQ(ScheduleWorker#reload_schedules) Reloading schedule: [Top Memory Consumers (weekly)] with id: [6]
[-] I 10:56:46.866728 #13460] : MIQ(MiqSchedule#next_interval_time) sch_start_time: 2015-07-22 00:00:00 UTC
[-] I 10:56:46.866902 #13460] : MIQ(MiqSchedule#next_interval_time) next_time: 2015-09-05 00:00:00 UTC
[-] I 10:56:46.867467 #13460] : MIQ(MiqSchedule#rufus_schedule_opts) Schedule [Top Memory Consumers (weekly)] scheduled to run at 2015-09-05 00:00:00 UTC with interval 86400
[-] I 10:56:46.867654 #13460] : MIQ(ScheduleWorker#reload_schedules) Reloading schedule: [Top Storage Consumers] with id: [7]
[-] I 10:56:46.868569 #13460] : MIQ(MiqSchedule#next_interval_time) sch_start_time: 2015-07-22 00:00:00 UTC
[-] I 10:56:46.868728 #13460] : MIQ(MiqSchedule#next_interval_time) next_time: 2015-09-05 00:00:00 UTC
[-] I 10:56:46.869310 #13460] : MIQ(MiqSchedule#rufus_schedule_opts) Schedule [Top Storage Consumers] scheduled to run at 2015-09-05 00:00:00 UTC with interval 86400
[-] I 10:56:46.869433 #13460] : MIQ(ScheduleWorker#reload_schedules) Reloading schedule: [EVM: Recently Discovered Hosts] with id: [8]
[-] I 10:56:46.870337 #13460] : MIQ(MiqSchedule#next_interval_time) sch_start_time: 2015-07-21 03:00:00 UTC
[-] I 10:56:46.870434 #13460] : MIQ(MiqSchedule#next_interval_time) next_time: 2015-09-04 15:00:00 UTC
[-] I 10:56:46.871005 #13460] : MIQ(MiqSchedule#rufus_schedule_opts) Schedule [EVM: Recently Discovered Hosts] scheduled to run at 2015-09-04 15:00:00 UTC with interval 3600
[-] I 10:56:46.871143 #13460] : MIQ(ScheduleWorker#reload_schedules) Reloading schedule: [EVM: Recently Discovered VMs] with id: [9]
[-] I 10:56:46.871996 #13460] : MIQ(MiqSchedule#next_interval_time) sch_start_time: 2015-07-21 03:00:00 UTC
[-] I 10:56:46.872104 #13460] : MIQ(MiqSchedule#next_interval_time) next_time: 2015-09-04 15:00:00 UTC
[-] I 10:56:46.872674 #13460] : MIQ(MiqSchedule#rufus_schedule_opts) Schedule [EVM: Recently Discovered VMs] scheduled to run at 2015-09-04 15:00:00 UTC with interval 3600
[-] I 10:56:46.872810 #13460] : MIQ(ScheduleWorker#do_work) Number of scheduled items to be processed: 0.
[-] I 10:56:46.942193 #13466] : MIQ(AutomateWorker#do_wait_for_worker_monitor) MIQ(AutomateWorker) Starting work since worker monitor has started
[-] I 10:56:46.982239 #13467] : MIQ(AutomateWorker#do_wait_for_worker_monitor) MIQ(AutomateWorker) Starting work since worker monitor has started
[-] I 10:56:49.372177 #13413] : MIQ(MiqServer#populate_queue_messages) Fetched 16 miq_queue rows for queue_name=generic, wcount=4, priority=200
[-] I 10:56:49.666117 #13453] : MIQ(PriorityWorker#get_message_via_drb) Message id: [2], MiqWorker id: [5], Zone: [default], Role: [], Server: [c69aab4c-4755-11e5-8436-b8e856479e14], Ident: [generic], Target id: [], Instance id: [3], Task id: [], Command: [MiqServer.ntp_reload], Timeout: [600], Priority: [20], State: [dequeue], Deliver On: [], Data: [], Args: [{:server=>["0.pool.ntp.org", "1.pool.ntp.org", "2.pool.ntp.org"]}], Dequeued in: [34.027186] seconds
[-] I 10:56:49.666222 #13453] : MIQ(MiqQueue#deliver) Message id: [2], Delivering...
[-] I 10:56:49.671902 #13453] : MIQ(MiqServer#ntp_reload) Synchronizing ntp settings: {:server=>["0.pool.ntp.org", "1.pool.ntp.org", "2.pool.ntp.org"]}
[-] I 10:56:49.672102 #13453] : MIQ(MiqQueue#delivered) Message id: [2], State: [ok], Delivered in [0.005887] seconds
[-] I 10:56:49.674860 #13452] : MIQ(PriorityWorker#get_message_via_drb) Message id: [4], MiqWorker id: [4], Zone: [default], Role: [], Server: [c69aab4c-4755-11e5-8436-b8e856479e14], Ident: [generic], Target id: [], Instance id: [3], Task id: [], Command: [MiqServer.delete_active_log_collections], Timeout: [600], Priority: [20], State: [dequeue], Deliver On: [], Data: [], Args: [], Dequeued in: [28.861965] seconds
[-] I 10:56:49.674959 #13452] : MIQ(MiqQueue#deliver) Message id: [4], Delivering...
[-] I 10:56:49.720095 #13452] : MIQ(MiqQueue#delivered) Message id: [4], State: [ok], Delivered in [0.045127] seconds
[-] I 10:56:50.966969 #13449] : MIQ(GenericWorker#get_message_via_drb) Message id: [1], MiqWorker id: [3], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [1], Task id: [], Command: [TimeProfile.rebuild_daily_metrics], Timeout: [3600], Priority: [100], State: [dequeue], Deliver On: [], Data: [], Args: [], Dequeued in: [3931077.405375] seconds
[-] I 10:56:50.967057 #13449] : MIQ(MiqQueue#deliver) Message id: [1], Delivering...
[-] I 10:56:51.011079 #13448] : MIQ(GenericWorker#get_message_via_drb) Message id: [3], MiqWorker id: [2], Zone: [], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqEvent.raise_evm_event], Timeout: [600], Priority: [100], State: [dequeue], Deliver On: [], Data: [], Args: [["MiqServer", 3], "evm_server_is_master", {:event_details=>"MiqServer [EVM] with ID: [3] has taken over master"}], Dequeued in: [30.384998] seconds
[-] I 10:56:51.011179 #13448] : MIQ(MiqQueue#deliver) Message id: [3], Delivering...
[-] I 10:56:51.021823 #13449] : MIQ(MiqQueue#delivered) Message id: [1], State: [ok], Delivered in [0.054762] seconds
[-] I 10:56:51.028053 #13449] : MIQ(GenericWorker#get_message_via_drb) Message id: [5], MiqWorker id: [3], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqEvent.raise_evm_event], Timeout: [600], Priority: [100], State: [dequeue], Deliver On: [], Data: [], Args: [["MiqServer", 3], "evm_worker_start", {:event_details=>"Worker started: ID [1], PID [], GUID [1ad4ce02-5315-11e5-8e34-b8e856479e14]", :type=>"MiqEventHandler"}], Dequeued in: [29.58918] seconds
[-] I 10:56:51.028138 #13449] : MIQ(MiqQueue#deliver) Message id: [5], Delivering...
[-] I 10:56:51.084044 #13448] : MIQ(MiqEvent.raise_evm_event) Event Raised [evm_server_is_master]
[-] I 10:56:51.096915 #13449] : MIQ(MiqEvent.raise_evm_event) Event Raised [evm_worker_start]
[-] I 10:56:51.178568 #13448] : MIQ(MiqEvent.raise_evm_event) Alert for Event [evm_server_is_master]
[-] I 10:56:51.187287 #13448] : MIQ(MiqAlert.evaluate_alerts) [evm_server_is_master] Target: MiqServer Name: [EVM], Id: [3]
[-] I 10:56:51.189955 #13449] : MIQ(MiqEvent.raise_evm_event) Alert for Event [evm_worker_start]
[-] I 10:56:51.198484 #13449] : MIQ(MiqAlert.evaluate_alerts) [evm_worker_start] Target: MiqServer Name: [EVM], Id: [3]
[-] I 10:56:51.204301 #13448] : MIQ(MiqQueue#delivered) Message id: [3], State: [ok], Delivered in [0.193125] seconds
[-] I 10:56:51.211218 #13448] : MIQ(GenericWorker#get_message_via_drb) Message id: [6], MiqWorker id: [2], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqEvent.raise_evm_event], Timeout: [600], Priority: [100], State: [dequeue], Deliver On: [], Data: [], Args: [["MiqServer", 3], "evm_worker_start", {:event_details=>"Worker started: ID [2], PID [], GUID [1af71d86-5315-11e5-8e34-b8e856479e14]", :type=>"MiqGenericWorker"}], Dequeued in: [29.553305] seconds
[-] I 10:56:51.211306 #13448] : MIQ(MiqQueue#deliver) Message id: [6], Delivering...
[-] I 10:56:51.213278 #13448] : MIQ(MiqEvent.raise_evm_event) Event Raised [evm_worker_start]
[-] I 10:56:51.215612 #13449] : MIQ(MiqQueue#delivered) Message id: [5], State: [ok], Delivered in [0.187469] seconds
[-] I 10:56:51.216564 #13448] : MIQ(MiqEvent.raise_evm_event) Alert for Event [evm_worker_start]
[-] I 10:56:51.216631 #13448] : MIQ(MiqAlert.evaluate_alerts) [evm_worker_start] Target: MiqServer Name: [EVM], Id: [3]
[-] I 10:56:51.217790 #13448] : MIQ(MiqQueue#delivered) Message id: [6], State: [ok], Delivered in [0.006487] seconds
[-] I 10:56:51.221606 #13449] : MIQ(GenericWorker#get_message_via_drb) Message id: [7], MiqWorker id: [3], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqEvent.raise_evm_event], Timeout: [600], Priority: [100], State: [dequeue], Deliver On: [], Data: [], Args: [["MiqServer", 3], "evm_worker_start", {:event_details=>"Worker started: ID [3], PID [], GUID [1af9dab2-5315-11e5-8e34-b8e856479e14]", :type=>"MiqGenericWorker"}], Dequeued in: [29.549821] seconds
[-] I 10:56:51.221681 #13449] : MIQ(MiqQueue#deliver) Message id: [7], Delivering...
[-] I 10:56:51.222986 #13448] : MIQ(GenericWorker#get_message_via_drb) Message id: [8], MiqWorker id: [2], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqEvent.raise_evm_event], Timeout: [600], Priority: [100], State: [dequeue], Deliver On: [], Data: [], Args: [["MiqServer", 3], "evm_worker_start", {:event_details=>"Worker started: ID [4], PID [], GUID [1b1b246a-5315-11e5-8e34-b8e856479e14]", :type=>"MiqPriorityWorker"}], Dequeued in: [29.327418] seconds
[-] I 10:56:51.223052 #13448] : MIQ(MiqQueue#deliver) Message id: [8], Delivering...
[-] I 10:56:51.223299 #13449] : MIQ(MiqEvent.raise_evm_event) Event Raised [evm_worker_start]
[-] I 10:56:51.224546 #13448] : MIQ(MiqEvent.raise_evm_event) Event Raised [evm_worker_start]
[-] I 10:56:51.226056 #13449] : MIQ(MiqEvent.raise_evm_event) Alert for Event [evm_worker_start]
[-] I 10:56:51.226159 #13449] : MIQ(MiqAlert.evaluate_alerts) [evm_worker_start] Target: MiqServer Name: [EVM], Id: [3]
[-] I 10:56:51.226374 #13449] : MIQ(MiqQueue#delivered) Message id: [7], State: [ok], Delivered in [0.004701] seconds
[-] I 10:56:51.227516 #13448] : MIQ(MiqEvent.raise_evm_event) Alert for Event [evm_worker_start]
[-] I 10:56:51.227575 #13448] : MIQ(MiqAlert.evaluate_alerts) [evm_worker_start] Target: MiqServer Name: [EVM], Id: [3]
[-] I 10:56:51.227753 #13448] : MIQ(MiqQueue#delivered) Message id: [8], State: [ok], Delivered in [0.004705] seconds
[-] I 10:56:51.232128 #13449] : MIQ(GenericWorker#get_message_via_drb) Message id: [9], MiqWorker id: [3], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqEvent.raise_evm_event], Timeout: [600], Priority: [100], State: [dequeue], Deliver On: [], Data: [], Args: [["MiqServer", 3], "evm_worker_start", {:event_details=>"Worker started: ID [5], PID [], GUID [1b1e67ba-5315-11e5-8e34-b8e856479e14]", :type=>"MiqPriorityWorker"}], Dequeued in: [29.317059] seconds
[-] I 10:56:51.232199 #13449] : MIQ(MiqQueue#deliver) Message id: [9], Delivering...
[-] I 10:56:51.233149 #13448] : MIQ(GenericWorker#get_message_via_drb) Message id: [10], MiqWorker id: [2], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqEvent.raise_evm_event], Timeout: [600], Priority: [100], State: [dequeue], Deliver On: [], Data: [], Args: [["MiqServer", 3], "evm_worker_start", {:event_details=>"Worker started: ID [6], PID [], GUID [1b49f6aa-5315-11e5-8e34-b8e856479e14]", :type=>"MiqReportingWorker"}], Dequeued in: [29.027311] seconds
[-] I 10:56:51.233217 #13448] : MIQ(MiqQueue#deliver) Message id: [10], Delivering...
[-] I 10:56:51.233795 #13449] : MIQ(MiqEvent.raise_evm_event) Event Raised [evm_worker_start]
[-] I 10:56:51.234809 #13448] : MIQ(MiqEvent.raise_evm_event) Event Raised [evm_worker_start]
[-] I 10:56:51.236410 #13449] : MIQ(MiqEvent.raise_evm_event) Alert for Event [evm_worker_start]
[-] I 10:56:51.236459 #13449] : MIQ(MiqAlert.evaluate_alerts) [evm_worker_start] Target: MiqServer Name: [EVM], Id: [3]
[-] I 10:56:51.236649 #13449] : MIQ(MiqQueue#delivered) Message id: [9], State: [ok], Delivered in [0.004456] seconds
[-] I 10:56:51.237293 #13448] : MIQ(MiqEvent.raise_evm_event) Alert for Event [evm_worker_start]
[-] I 10:56:51.237341 #13448] : MIQ(MiqAlert.evaluate_alerts) [evm_worker_start] Target: MiqServer Name: [EVM], Id: [3]
[-] I 10:56:51.237497 #13448] : MIQ(MiqQueue#delivered) Message id: [10], State: [ok], Delivered in [0.004283] seconds
[-] I 10:56:51.242201 #13449] : MIQ(GenericWorker#get_message_via_drb) Message id: [11], MiqWorker id: [3], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqEvent.raise_evm_event], Timeout: [600], Priority: [100], State: [dequeue], Deliver On: [], Data: [], Args: [["MiqServer", 3], "evm_worker_start", {:event_details=>"Worker started: ID [7], PID [], GUID [1b4f11f8-5315-11e5-8e34-b8e856479e14]", :type=>"MiqReportingWorker"}], Dequeued in: [29.010161] seconds
[-] I 10:56:51.242269 #13449] : MIQ(MiqQueue#deliver) Message id: [11], Delivering...
[-] I 10:56:51.243080 #13448] : MIQ(GenericWorker#get_message_via_drb) Message id: [12], MiqWorker id: [2], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqEvent.raise_evm_event], Timeout: [600], Priority: [100], State: [dequeue], Deliver On: [], Data: [], Args: [["MiqServer", 3], "evm_worker_start", {:event_details=>"Worker started: ID [8], PID [], GUID [1b8c860a-5315-11e5-8e34-b8e856479e14]", :type=>"MiqScheduleWorker"}], Dequeued in: [28.601393] seconds
[-] I 10:56:51.243148 #13448] : MIQ(MiqQueue#deliver) Message id: [12], Delivering...
[-] I 10:56:51.243798 #13449] : MIQ(MiqEvent.raise_evm_event) Event Raised [evm_worker_start]
[-] I 10:56:51.244627 #13448] : MIQ(MiqEvent.raise_evm_event) Event Raised [evm_worker_start]
[-] I 10:56:51.246201 #13449] : MIQ(MiqEvent.raise_evm_event) Alert for Event [evm_worker_start]
[-] I 10:56:51.246245 #13449] : MIQ(MiqAlert.evaluate_alerts) [evm_worker_start] Target: MiqServer Name: [EVM], Id: [3]
[-] I 10:56:51.246391 #13449] : MIQ(MiqQueue#delivered) Message id: [11], State: [ok], Delivered in [0.004125] seconds
[-] I 10:56:51.246972 #13448] : MIQ(MiqEvent.raise_evm_event) Alert for Event [evm_worker_start]
[-] I 10:56:51.247018 #13448] : MIQ(MiqAlert.evaluate_alerts) [evm_worker_start] Target: MiqServer Name: [EVM], Id: [3]
[-] I 10:56:51.247188 #13448] : MIQ(MiqQueue#delivered) Message id: [12], State: [ok], Delivered in [0.004046] seconds
[-] I 10:56:51.251855 #13449] : MIQ(GenericWorker#get_message_via_drb) Message id: [13], MiqWorker id: [3], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqEvent.raise_evm_event], Timeout: [600], Priority: [100], State: [dequeue], Deliver On: [], Data: [], Args: [["MiqServer", 3], "evm_worker_start", {:event_details=>"Worker started: ID [9], PID [], GUID [1bc08720-5315-11e5-8e34-b8e856479e14]", :type=>"MiqUiWorker"}], Dequeued in: [28.261571] seconds
[-] I 10:56:51.251924 #13449] : MIQ(MiqQueue#deliver) Message id: [13], Delivering...
[-] I 10:56:51.252596 #13448] : MIQ(GenericWorker#get_message_via_drb) Message id: [14], MiqWorker id: [2], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqEvent.raise_evm_event], Timeout: [600], Priority: [100], State: [dequeue], Deliver On: [], Data: [], Args: [["MiqServer", 3], "evm_worker_start", {:event_details=>"Worker started: ID [10], PID [], GUID [1c1ac9c4-5315-11e5-8e34-b8e856479e14]", :type=>"MiqWebServiceWorker"}], Dequeued in: [27.664879] seconds
[-] I 10:56:51.252665 #13448] : MIQ(MiqQueue#deliver) Message id: [14], Delivering...
[-] I 10:56:51.253455 #13449] : MIQ(MiqEvent.raise_evm_event) Event Raised [evm_worker_start]
[-] I 10:56:51.254143 #13448] : MIQ(MiqEvent.raise_evm_event) Event Raised [evm_worker_start]
[-] I 10:56:51.255817 #13449] : MIQ(MiqEvent.raise_evm_event) Alert for Event [evm_worker_start]
[-] I 10:56:51.255862 #13449] : MIQ(MiqAlert.evaluate_alerts) [evm_worker_start] Target: MiqServer Name: [EVM], Id: [3]
[-] I 10:56:51.256031 #13449] : MIQ(MiqQueue#delivered) Message id: [13], State: [ok], Delivered in [0.00411] seconds
[-] I 10:56:51.256539 #13448] : MIQ(MiqEvent.raise_evm_event) Alert for Event [evm_worker_start]
[-] I 10:56:51.256587 #13448] : MIQ(MiqAlert.evaluate_alerts) [evm_worker_start] Target: MiqServer Name: [EVM], Id: [3]
[-] I 10:56:51.256747 #13448] : MIQ(MiqQueue#delivered) Message id: [14], State: [ok], Delivered in [0.004087] seconds
[-] I 10:56:51.261487 #13449] : MIQ(GenericWorker#get_message_via_drb) Message id: [15], MiqWorker id: [3], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqEvent.raise_evm_event], Timeout: [600], Priority: [100], State: [dequeue], Deliver On: [], Data: [], Args: [["MiqServer", 3], "evm_worker_start", {:event_details=>"Worker started: ID [11], PID [], GUID [1c5a0e36-5315-11e5-8e34-b8e856479e14]", :type=>"MiqAutomateWorker"}], Dequeued in: [27.272457] seconds
[-] I 10:56:51.261583 #13449] : MIQ(MiqQueue#deliver) Message id: [15], Delivering...
[-] I 10:56:51.262425 #13448] : MIQ(GenericWorker#get_message_via_drb) Message id: [16], MiqWorker id: [2], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqEvent.raise_evm_event], Timeout: [600], Priority: [100], State: [dequeue], Deliver On: [], Data: [], Args: [["MiqServer", 3], "evm_worker_start", {:event_details=>"Worker started: ID [12], PID [], GUID [1c5e7804-5315-11e5-8e34-b8e856479e14]", :type=>"MiqAutomateWorker"}], Dequeued in: [27.250916] seconds
[-] I 10:56:51.262500 #13448] : MIQ(MiqQueue#deliver) Message id: [16], Delivering...
[-] I 10:56:51.263199 #13449] : MIQ(MiqEvent.raise_evm_event) Event Raised [evm_worker_start]
[-] I 10:56:51.264062 #13448] : MIQ(MiqEvent.raise_evm_event) Event Raised [evm_worker_start]
[-] I 10:56:51.265707 #13449] : MIQ(MiqEvent.raise_evm_event) Alert for Event [evm_worker_start]
[-] I 10:56:51.265758 #13449] : MIQ(MiqAlert.evaluate_alerts) [evm_worker_start] Target: MiqServer Name: [EVM], Id: [3]
[-] I 10:56:51.265925 #13449] : MIQ(MiqQueue#delivered) Message id: [15], State: [ok], Delivered in [0.004348] seconds
[-] I 10:56:51.266431 #13448] : MIQ(MiqEvent.raise_evm_event) Alert for Event [evm_worker_start]
[-] I 10:56:51.266480 #13448] : MIQ(MiqAlert.evaluate_alerts) [evm_worker_start] Target: MiqServer Name: [EVM], Id: [3]
[-] I 10:56:51.266635 #13448] : MIQ(MiqQueue#delivered) Message id: [16], State: [ok], Delivered in [0.004145] seconds
[-] I 10:57:01.989697 #13460] : MIQ(ScheduleWorker#do_work) Number of scheduled items to be processed: 1.
[-] I 10:57:02.013522 #13460] : MIQ(MiqQueue.put) Message id: [17], id: [], Zone: [default], Role: [smartstate], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [job_dispatcher], Command: [JobProxyDispatcher.dispatch], Timeout: [600], Priority: [20], State: [ready], Deliver On: [], Data: [], Args: []
[-] I 10:57:04.597189 #13413] : MIQ(MiqServer#populate_queue_messages) Fetched 1 miq_queue rows for queue_name=generic, wcount=4, priority=200
[-] I 10:57:04.777932 #13453] : MIQ(PriorityWorker#get_message_via_drb) Message id: [17], MiqWorker id: [5], Zone: [default], Role: [smartstate], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [job_dispatcher], Command: [JobProxyDispatcher.dispatch], Timeout: [600], Priority: [20], State: [dequeue], Deliver On: [], Data: [], Args: [], Dequeued in: [2.768379] seconds
[-] I 10:57:04.778010 #13453] : Q-task_id([job_dispatcher]) MIQ(MiqQueue#deliver) Message id: [17], Delivering...
[-] I 10:57:04.791332 #13453] : Q-task_id([job_dispatcher]) MIQ(JobProxyDispatcher#dispatch) Complete - Timings: {:pending_jobs=>0.008683919906616211, :jobs_to_dispatch_count=>0, :total_time=>0.010965108871459961}
[-] I 10:57:04.791628 #13453] : Q-task_id([job_dispatcher]) MIQ(MiqQueue#delivered) Message id: [17], State: [ok], Delivered in [0.013619] seconds
[-] I 10:57:14.613270 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:57:14 UTC]...
[-] I 10:57:14.619237 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:57:14 UTC]...Complete
[-] I 10:57:17.020267 #13460] : MIQ(ScheduleWorker#do_work) Number of scheduled items to be processed: 2.
[-] I 10:57:17.027550 #13460] : MIQ(MiqQueue.put) Message id: [18], id: [], Zone: [default], Role: [], Server: [c69aab4c-4755-11e5-8436-b8e856479e14], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [Session.check_session_timeout], Timeout: [600], Priority: [90], State: [ready], Deliver On: [], Data: [], Args: []
[-] I 10:57:17.032193 #13460] : MIQ(MiqQueue.put) Message id: [19], id: [], Zone: [default], Role: [smartstate], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [job_dispatcher], Command: [JobProxyDispatcher.dispatch], Timeout: [600], Priority: [20], State: [ready], Deliver On: [], Data: [], Args: []
[-] I 10:57:19.827408 #13413] : MIQ(MiqServer#populate_queue_messages) Fetched 2 miq_queue rows for queue_name=generic, wcount=4, priority=200
[-] I 10:57:19.896388 #13453] : MIQ(PriorityWorker#get_message_via_drb) Message id: [19], MiqWorker id: [5], Zone: [default], Role: [smartstate], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [job_dispatcher], Command: [JobProxyDispatcher.dispatch], Timeout: [600], Priority: [20], State: [dequeue], Deliver On: [], Data: [], Args: [], Dequeued in: [2.865808] seconds
[-] I 10:57:19.896475 #13453] : Q-task_id([job_dispatcher]) MIQ(MiqQueue#deliver) Message id: [19], Delivering...
[-] I 10:57:19.897693 #13453] : Q-task_id([job_dispatcher]) MIQ(JobProxyDispatcher#dispatch) Complete - Timings: {:pending_jobs=>0.00034809112548828125, :jobs_to_dispatch_count=>0, :total_time=>0.0010671615600585938}
[-] I 10:57:19.897823 #13453] : Q-task_id([job_dispatcher]) MIQ(MiqQueue#delivered) Message id: [19], State: [ok], Delivered in [0.001353] seconds
[-] I 10:57:21.320393 #13449] : MIQ(GenericWorker#get_message_via_drb) Message id: [18], MiqWorker id: [3], Zone: [default], Role: [], Server: [c69aab4c-4755-11e5-8436-b8e856479e14], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [Session.check_session_timeout], Timeout: [600], Priority: [90], State: [dequeue], Deliver On: [], Data: [], Args: [], Dequeued in: [4.296294] seconds
[-] I 10:57:21.320525 #13449] : MIQ(MiqQueue#deliver) Message id: [18], Delivering...
[-] I 10:57:21.330299 #13449] : MIQ(MiqQueue#delivered) Message id: [18], State: [ok], Delivered in [0.009768] seconds
[-] I 10:57:32.035470 #13460] : MIQ(ScheduleWorker#do_work) Number of scheduled items to be processed: 1.
[-] I 10:57:32.041351 #13460] : MIQ(MiqQueue.put) Message id: [20], id: [], Zone: [default], Role: [smartstate], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [job_dispatcher], Command: [JobProxyDispatcher.dispatch], Timeout: [600], Priority: [20], State: [ready], Deliver On: [], Data: [], Args: []
[-] I 10:57:35.037285 #13413] : MIQ(MiqServer#populate_queue_messages) Fetched 1 miq_queue rows for queue_name=generic, wcount=4, priority=200
[-] I 10:57:36.008843 #13452] : MIQ(PriorityWorker#get_message_via_drb) Message id: [20], MiqWorker id: [4], Zone: [default], Role: [smartstate], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [job_dispatcher], Command: [JobProxyDispatcher.dispatch], Timeout: [600], Priority: [20], State: [dequeue], Deliver On: [], Data: [], Args: [], Dequeued in: [3.969427] seconds
[-] I 10:57:36.008922 #13452] : Q-task_id([job_dispatcher]) MIQ(MiqQueue#deliver) Message id: [20], Delivering...
[-] I 10:57:36.028360 #13452] : Q-task_id([job_dispatcher]) MIQ(JobProxyDispatcher#dispatch) Complete - Timings: {:pending_jobs=>0.00887918472290039, :jobs_to_dispatch_count=>0, :total_time=>0.01016688346862793}
[-] I 10:57:36.028535 #13452] : Q-task_id([job_dispatcher]) MIQ(MiqQueue#delivered) Message id: [20], State: [ok], Delivered in [0.019618] seconds
[-] I 10:57:45.055401 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:57:45 UTC]...
[-] I 10:57:45.062614 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:57:45 UTC]...Complete
[-] I 10:57:47.049629 #13460] : MIQ(ScheduleWorker#do_work) Number of scheduled items to be processed: 6.
[-] I 10:57:47.054833 #13460] : MIQ(MiqQueue.put) Message id: [21], id: [], Zone: [default], Role: [], Server: [c69aab4c-4755-11e5-8436-b8e856479e14], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqServer.status_update], Timeout: [600], Priority: [20], State: [ready], Deliver On: [], Data: [], Args: []
[-] I 10:57:47.058469 #13460] : MIQ(MiqQueue.put) Message id: [22], id: [], Zone: [default], Role: [], Server: [c69aab4c-4755-11e5-8436-b8e856479e14], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqDbConfig.log_statistics], Timeout: [600], Priority: [90], State: [ready], Deliver On: [], Data: [], Args: []
[-] I 10:57:47.062713 #13460] : MIQ(MiqQueue.put) Message id: [23], id: [], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [Job.check_jobs_for_timeout], Timeout: [600], Priority: [90], State: [ready], Deliver On: [], Data: [], Args: []
[-] I 10:57:47.068544 #13460] : MIQ(MiqQueue.put) Message id: [24], id: [], Zone: [default], Role: [], Server: [c69aab4c-4755-11e5-8436-b8e856479e14], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [Session.check_session_timeout], Timeout: [600], Priority: [90], State: [ready], Deliver On: [], Data: [], Args: []
[-] I 10:57:47.072682 #13460] : MIQ(MiqQueue.put) Message id: [25], id: [], Zone: [default], Role: [smartstate], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [job_dispatcher], Command: [JobProxyDispatcher.dispatch], Timeout: [600], Priority: [20], State: [ready], Deliver On: [], Data: [], Args: []
[-] I 10:57:50.311636 #13413] : MIQ(MiqServer#populate_queue_messages) Fetched 5 miq_queue rows for queue_name=generic, wcount=4, priority=200
[-] I 10:57:51.099077 #13453] : MIQ(PriorityWorker#get_message_via_drb) Message id: [21], MiqWorker id: [5], Zone: [default], Role: [], Server: [c69aab4c-4755-11e5-8436-b8e856479e14], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqServer.status_update], Timeout: [600], Priority: [20], State: [dequeue], Deliver On: [], Data: [], Args: [], Dequeued in: [4.046256] seconds
[-] I 10:57:51.099157 #13453] : MIQ(MiqQueue#deliver) Message id: [21], Delivering...
[-] I 10:57:51.110419 #13453] : MIQ(MiqQueue#delivered) Message id: [21], State: [ok], Delivered in [0.011245] seconds
[-] I 10:57:51.117430 #13453] : MIQ(PriorityWorker#get_message_via_drb) Message id: [25], MiqWorker id: [5], Zone: [default], Role: [smartstate], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [job_dispatcher], Command: [JobProxyDispatcher.dispatch], Timeout: [600], Priority: [20], State: [dequeue], Deliver On: [], Data: [], Args: [], Dequeued in: [4.046223] seconds
[-] I 10:57:51.117518 #13453] : Q-task_id([job_dispatcher]) MIQ(MiqQueue#deliver) Message id: [25], Delivering...
[-] I 10:57:51.118924 #13453] : Q-task_id([job_dispatcher]) MIQ(JobProxyDispatcher#dispatch) Complete - Timings: {:pending_jobs=>0.0003540515899658203, :jobs_to_dispatch_count=>0, :total_time=>0.0012369155883789062}
[-] I 10:57:51.119085 #13453] : Q-task_id([job_dispatcher]) MIQ(MiqQueue#delivered) Message id: [25], State: [ok], Delivered in [0.001572] seconds
[-] I 10:57:51.391825 #13448] : MIQ(GenericWorker#get_message_via_drb) Message id: [22], MiqWorker id: [2], Zone: [default], Role: [], Server: [c69aab4c-4755-11e5-8436-b8e856479e14], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqDbConfig.log_statistics], Timeout: [600], Priority: [90], State: [dequeue], Deliver On: [], Data: [], Args: [], Dequeued in: [4.334981] seconds
[-] I 10:57:51.391911 #13448] : MIQ(MiqQueue#deliver) Message id: [22], Delivering...
[-] I 10:57:51.397481 #13449] : MIQ(GenericWorker#get_message_via_drb) Message id: [23], MiqWorker id: [3], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [Job.check_jobs_for_timeout], Timeout: [600], Priority: [90], State: [dequeue], Deliver On: [], Data: [], Args: [], Dequeued in: [4.336362] seconds
[-] I 10:57:51.397569 #13449] : MIQ(MiqQueue#deliver) Message id: [23], Delivering...
[-] I 10:57:51.409291 #13449] : MIQ(MiqQueue#delivered) Message id: [23], State: [ok], Delivered in [0.011719] seconds
[-] I 10:57:51.414799 #13449] : MIQ(GenericWorker#get_message_via_drb) Message id: [24], MiqWorker id: [3], Zone: [default], Role: [], Server: [c69aab4c-4755-11e5-8436-b8e856479e14], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [Session.check_session_timeout], Timeout: [600], Priority: [90], State: [dequeue], Deliver On: [], Data: [], Args: [], Dequeued in: [4.347821] seconds
[-] I 10:57:51.414879 #13449] : MIQ(MiqQueue#deliver) Message id: [24], Delivering...
[-] I 10:57:51.419561 #13449] : MIQ(MiqQueue#delivered) Message id: [24], State: [ok], Delivered in [0.004679] seconds
[-] I 10:57:51.447888 #13448] : MIQ(DbConfig.log_activity_statistics) <<-ACTIVITY_STATS_CSV
session_id,xact_start,last_request_start_time,command,task_state,login,application,request_id,net_address,host_name,client_port,wait_time_ms,blocked_by
13519,,2015-09-04 14:57:50 UTC,"SELECT id, lock_version, priority, role FROM ""miq_queue"" WHERE ( state = 'ready'
AND (zone IS NULL OR zone = 'default')
AND queue_name = 'automate'
AND (role IS NULL OR role IN ('automate','database_operations','database_owner','ems_inventory','ems_operations','event','reporting','scheduler','smartstate','user_interface','web_services'))
AND (server_guid IS NULL OR server_guid = 'c69aab4c-4755-11e5-8436-b8e856479e14')
AND (deliver_on IS NULL OR deliver_on <= '2015-09-04 14:57:50.312569')
AND (priority <= 200)
) ORDER BY ""miq_queue"".""priority"" ASC, ""miq_queue"".""id"" ASC LIMIT 200",false,postgres,/Users/kbrock/src/manageiq/lib/workers/bin/evm_server.rb,16384,,,-1,1,
13507,,2015-09-04 14:57:50 UTC,SELECT pg_backend_pid(),false,postgres,/Users/kbrock/src/manageiq/lib/workers/bin/worker.rb,16384,,,-1,0,
13508,,2015-09-04 14:57:51 UTC,COMMIT,false,postgres,/Users/kbrock/src/manageiq/lib/workers/bin/worker.rb,16384,,,-1,0,
13509,2015-09-04 14:57:51 UTC,2015-09-04 14:57:51 UTC,"SELECT ""pg_stat_activity"".* FROM ""pg_stat_activity"" WHERE ""pg_stat_activity"".""datname"" = $1",false,postgres,/Users/kbrock/src/manageiq/lib/workers/bin/worker.rb,16384,,,-1,0,
13510,,2015-09-04 14:57:51 UTC,SELECT pg_backend_pid(),false,postgres,/Users/kbrock/src/manageiq/lib/workers/bin/worker.rb,16384,,,-1,0,
13511,,2015-09-04 14:57:51 UTC,SELECT pg_backend_pid(),false,postgres,/Users/kbrock/src/manageiq/lib/workers/bin/worker.rb,16384,,,-1,0,
13512,,2015-09-04 14:57:49 UTC,SELECT pg_backend_pid(),false,postgres,/Users/kbrock/src/manageiq/lib/workers/bin/worker.rb,16384,,,-1,2,
13513,,2015-09-04 14:57:49 UTC,SELECT pg_backend_pid(),false,postgres,/Users/kbrock/src/manageiq/lib/workers/bin/worker.rb,16384,,,-1,2,
13514,,2015-09-04 14:56:43 UTC,"SELECT ""miq_servers"".* FROM ""miq_servers"" WHERE ""miq_servers"".""id"" = $1 LIMIT 1",false,postgres,/Users/kbrock/src/manageiq/bin/rails,16384,,,-1,68,
13515,,2015-09-04 14:57:47 UTC,"SELECT ""miq_schedules"".* FROM ""miq_schedules"" WHERE (updated_at > '2015-09-04 14:57:32.044088')",false,postgres,/Users/kbrock/src/manageiq/lib/workers/bin/worker.rb,16384,,,-1,4,
13516,,2015-09-04 14:56:43 UTC,"SELECT ""miq_servers"".* FROM ""miq_servers"" WHERE ""miq_servers"".""id"" = $1 LIMIT 1",false,postgres,/Users/kbrock/src/manageiq/bin/rails,16384,,,-1,67,
13517,,2015-09-04 14:57:50 UTC,SELECT pg_backend_pid(),false,postgres,/Users/kbrock/src/manageiq/lib/workers/bin/worker.rb,16384,,,-1,1,
13518,,2015-09-04 14:57:50 UTC,SELECT pg_backend_pid(),false,postgres,/Users/kbrock/src/manageiq/lib/workers/bin/worker.rb,16384,,,-1,1,
ACTIVITY_STATS_CSV
[-] I 10:57:51.448112 #13448] : MIQ(MiqQueue#delivered) Message id: [22], State: [ok], Delivered in [0.056203] seconds
[-] I 10:58:01.057270 #13667] : MIQ(Vmdb::Loggers.apply_config) Log level for vim.log has been changed to [WARN]
[-] I 10:58:02.077545 #13460] : MIQ(ScheduleWorker#do_work) Number of scheduled items to be processed: 1.
[-] I 10:58:02.082247 #13460] : MIQ(MiqQueue.put) Message id: [26], id: [], Zone: [default], Role: [smartstate], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [job_dispatcher], Command: [JobProxyDispatcher.dispatch], Timeout: [600], Priority: [20], State: [ready], Deliver On: [], Data: [], Args: []
[-] I 10:58:02.491569 #13667] : MIQ(Vmdb::Initializer.init) - Program Name: /Users/kbrock/.gem/ruby/2.2.2/bin/rake, PID: 13667, ENV['MIQ_GUID']: , ENV['EVMSERVER']:
[-] I 10:58:02.496325 #13667] : MIQ(Vmdb::Initializer.init) - Init complete
[-] I 10:58:03.096683 #13667] : MIQ(EvmApplication.stop) EVM Shutdown initiated
[-] I 10:58:03.403156 #13667] : MIQ(MiqQueue.put) Message id: [27], id: [], Zone: [default], Role: [], Server: [c69aab4c-4755-11e5-8436-b8e856479e14], Ident: [miq_server], Target id: [], Instance id: [3], Task id: [], Command: [MiqServer.shutdown_and_exit], Timeout: [600], Priority: [100], State: [ready], Deliver On: [], Data: [], Args: []
[-] I 10:58:05.346956 #13413] : MIQ(MiqQueue.get) Message id: [27], MiqServer id: [3], Zone: [default], Role: [], Server: [c69aab4c-4755-11e5-8436-b8e856479e14], Ident: [miq_server], Target id: [], Instance id: [3], Task id: [], Command: [MiqServer.shutdown_and_exit], Timeout: [600], Priority: [100], State: [dequeue], Deliver On: [], Data: [], Args: [], Dequeued in: [1.964948] seconds
[-] I 10:58:05.347054 #13413] : MIQ(MiqQueue#deliver) Message id: [27], Delivering...
[-] I 10:58:05.347325 #13413] : MIQ(MiqServer#shutdown) initiated for MiqServer [EVM] with ID: [3], PID: [13413], GUID: [c69aab4c-4755-11e5-8436-b8e856479e14]
[-] I 10:58:05.351636 #13413] : MIQ(MiqEvent.raise_evm_event) Event Raised [evm_server_stop]
[-] I 10:58:05.356754 #13413] : MIQ(MiqEvent.raise_evm_event) Alert for Event [evm_server_stop]
[-] I 10:58:05.356835 #13413] : MIQ(MiqAlert.evaluate_alerts) [evm_server_stop] Target: MiqServer Name: [EVM], Id: [3]
[-] I 10:58:05.366524 #13413] : MIQ(AssignedServerRole#deactivate) Deactivating Role <automate> on Server <EVM>
[-] I 10:58:05.368651 #13413] : MIQ(AssignedServerRole#deactivate) Deactivating Role <database_operations> on Server <EVM>
[-] I 10:58:05.369882 #13413] : MIQ(AssignedServerRole#deactivate) Deactivating Role <ems_inventory> on Server <EVM>
[-] I 10:58:05.372308 #13413] : MIQ(AssignedServerRole#deactivate) Deactivating Role <ems_operations> on Server <EVM>
[-] I 10:58:05.374423 #13413] : MIQ(AssignedServerRole#deactivate) Deactivating Role <event> on Server <EVM>
[-] I 10:58:05.375990 #13413] : MIQ(AssignedServerRole#deactivate) Deactivating Role <reporting> on Server <EVM>
[-] I 10:58:05.377549 #13413] : MIQ(AssignedServerRole#deactivate) Deactivating Role <scheduler> on Server <EVM>
[-] I 10:58:05.379673 #13413] : MIQ(AssignedServerRole#deactivate) Deactivating Role <smartstate> on Server <EVM>
[-] I 10:58:05.381923 #13413] : MIQ(AssignedServerRole#deactivate) Deactivating Role <user_interface> on Server <EVM>
[-] I 10:58:05.383430 #13413] : MIQ(AssignedServerRole#deactivate) Deactivating Role <web_services> on Server <EVM>
[-] I 10:58:05.384917 #13413] : MIQ(MiqServer#quiesce_workers_loop) Stopping all active workers
[-] I 10:58:05.385096 #13413] : MIQ(MiqServer#stop_worker) Stopping Worker [MiqAutomateWorker] with ID: [12], PID: [13467], GUID: [1c5e7804-5315-11e5-8e34-b8e856479e14], status [started]...
[-] I 10:58:05.389888 #13413] : MIQ(MiqQueue.put) Message id: [28], id: [], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqEvent.raise_evm_event], Timeout: [600], Priority: [100], State: [ready], Deliver On: [], Data: [], Args: [["MiqServer", 3], "evm_worker_stop", {:event_details=>"Stopping Worker [MiqAutomateWorker] with ID: [12], PID: [13467], GUID: [1c5e7804-5315-11e5-8e34-b8e856479e14], status [started]...", :type=>"MiqAutomateWorker"}]
[-] I 10:58:05.391590 #13413] : MIQ(MiqServer#worker_set_message) Worker [MiqAutomateWorker] with ID: [12], PID: [13467], GUID: [1c5e7804-5315-11e5-8e34-b8e856479e14] is being requested to exit
[-] I 10:58:05.391679 #13413] : MIQ(MiqServer#stop_worker) Stopping Worker [MiqScheduleWorker] with ID: [8], PID: [13460], GUID: [1b8c860a-5315-11e5-8e34-b8e856479e14], status [started]...
[-] I 10:58:05.395036 #13413] : MIQ(MiqQueue.put) Message id: [29], id: [], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqEvent.raise_evm_event], Timeout: [600], Priority: [100], State: [ready], Deliver On: [], Data: [], Args: [["MiqServer", 3], "evm_worker_stop", {:event_details=>"Stopping Worker [MiqScheduleWorker] with ID: [8], PID: [13460], GUID: [1b8c860a-5315-11e5-8e34-b8e856479e14], status [started]...", :type=>"MiqScheduleWorker"}]
[-] I 10:58:05.396348 #13413] : MIQ(MiqServer#worker_set_message) Worker [MiqScheduleWorker] with ID: [8], PID: [13460], GUID: [1b8c860a-5315-11e5-8e34-b8e856479e14] is being requested to exit
[-] I 10:58:05.396421 #13413] : MIQ(MiqServer#stop_worker) Stopping Worker [MiqEventHandler] with ID: [1], PID: [13446], GUID: [1ad4ce02-5315-11e5-8e34-b8e856479e14], status [started]...
[-] I 10:58:05.399730 #13413] : MIQ(MiqQueue.put) Message id: [30], id: [], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqEvent.raise_evm_event], Timeout: [600], Priority: [100], State: [ready], Deliver On: [], Data: [], Args: [["MiqServer", 3], "evm_worker_stop", {:event_details=>"Stopping Worker [MiqEventHandler] with ID: [1], PID: [13446], GUID: [1ad4ce02-5315-11e5-8e34-b8e856479e14], status [started]...", :type=>"MiqEventHandler"}]
[-] I 10:58:05.401174 #13413] : MIQ(MiqServer#worker_set_message) Worker [MiqEventHandler] with ID: [1], PID: [13446], GUID: [1ad4ce02-5315-11e5-8e34-b8e856479e14] is being requested to exit
[-] I 10:58:05.401254 #13413] : MIQ(MiqServer#stop_worker) Stopping Worker [MiqPriorityWorker] with ID: [5], PID: [13453], GUID: [1b1e67ba-5315-11e5-8e34-b8e856479e14], status [started]...
[-] I 10:58:05.404902 #13413] : MIQ(MiqQueue.put) Message id: [31], id: [], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqEvent.raise_evm_event], Timeout: [600], Priority: [100], State: [ready], Deliver On: [], Data: [], Args: [["MiqServer", 3], "evm_worker_stop", {:event_details=>"Stopping Worker [MiqPriorityWorker] with ID: [5], PID: [13453], GUID: [1b1e67ba-5315-11e5-8e34-b8e856479e14], status [started]...", :type=>"MiqPriorityWorker"}]
[-] I 10:58:05.406504 #13413] : MIQ(MiqServer#worker_set_message) Worker [MiqPriorityWorker] with ID: [5], PID: [13453], GUID: [1b1e67ba-5315-11e5-8e34-b8e856479e14] is being requested to exit
[-] I 10:58:05.406588 #13413] : MIQ(MiqServer#stop_worker) Stopping Worker [MiqGenericWorker] with ID: [2], PID: [13448], GUID: [1af71d86-5315-11e5-8e34-b8e856479e14], status [started]...
[-] I 10:58:05.410030 #13413] : MIQ(MiqQueue.put) Message id: [32], id: [], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqEvent.raise_evm_event], Timeout: [600], Priority: [100], State: [ready], Deliver On: [], Data: [], Args: [["MiqServer", 3], "evm_worker_stop", {:event_details=>"Stopping Worker [MiqGenericWorker] with ID: [2], PID: [13448], GUID: [1af71d86-5315-11e5-8e34-b8e856479e14], status [started]...", :type=>"MiqGenericWorker"}]
[-] I 10:58:05.411381 #13413] : MIQ(MiqServer#worker_set_message) Worker [MiqGenericWorker] with ID: [2], PID: [13448], GUID: [1af71d86-5315-11e5-8e34-b8e856479e14] is being requested to exit
[-] I 10:58:05.411457 #13413] : MIQ(MiqServer#stop_worker) Stopping Worker [MiqUiWorker] with ID: [9], PID: [13462], GUID: [1bc08720-5315-11e5-8e34-b8e856479e14], status [started]...
[-] I 10:58:05.414693 #13413] : MIQ(MiqQueue.put) Message id: [33], id: [], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqEvent.raise_evm_event], Timeout: [600], Priority: [100], State: [ready], Deliver On: [], Data: [], Args: [["MiqServer", 3], "evm_worker_stop", {:event_details=>"Stopping Worker [MiqUiWorker] with ID: [9], PID: [13462], GUID: [1bc08720-5315-11e5-8e34-b8e856479e14], status [started]...", :type=>"MiqUiWorker"}]
[-] I 10:58:05.414777 #13413] : MIQ(MiqUiWorker#terminate) Terminating Worker [MiqUiWorker] with ID: [9], PID: [13462], GUID: [1bc08720-5315-11e5-8e34-b8e856479e14], status [started]
[-] I 10:58:06.337575 #13462] : MIQ(MiqUiWorker#log_status) [User Interface Worker] Worker ID [9], PID [13462], GUID [1bc08720-5315-11e5-8e34-b8e856479e14], Last Heartbeat [2015-09-04 14:57:43 UTC], Process Info: Memory Usage [211496960], Memory Size [2771415040], Memory % [1.2], CPU Time [840.0], CPU % [0.0], Priority [31]
[-] I 10:58:06.337761 #13462] : MIQ(UiWorker) ID [9] PID [13462] GUID [1bc08720-5315-11e5-8e34-b8e856479e14] Exit request received. Worker exiting.
[-] I 10:58:07.422065 #13413] : MIQ(MiqServer#stop_worker) Stopping Worker [MiqReportingWorker] with ID: [6], PID: [13456], GUID: [1b49f6aa-5315-11e5-8e34-b8e856479e14], status [started]...
[-] I 10:58:07.429056 #13413] : MIQ(MiqQueue.put) Message id: [34], id: [], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqEvent.raise_evm_event], Timeout: [600], Priority: [100], State: [ready], Deliver On: [], Data: [], Args: [["MiqServer", 3], "evm_worker_stop", {:event_details=>"Stopping Worker [MiqReportingWorker] with ID: [6], PID: [13456], GUID: [1b49f6aa-5315-11e5-8e34-b8e856479e14], status [started]...", :type=>"MiqReportingWorker"}]
[-] I 10:58:07.431005 #13413] : MIQ(MiqServer#worker_set_message) Worker [MiqReportingWorker] with ID: [6], PID: [13456], GUID: [1b49f6aa-5315-11e5-8e34-b8e856479e14] is being requested to exit
[-] I 10:58:07.431120 #13413] : MIQ(MiqServer#stop_worker) Stopping Worker [MiqWebServiceWorker] with ID: [10], PID: [13464], GUID: [1c1ac9c4-5315-11e5-8e34-b8e856479e14], status [started]...
[-] I 10:58:07.435202 #13413] : MIQ(MiqQueue.put) Message id: [35], id: [], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqEvent.raise_evm_event], Timeout: [600], Priority: [100], State: [ready], Deliver On: [], Data: [], Args: [["MiqServer", 3], "evm_worker_stop", {:event_details=>"Stopping Worker [MiqWebServiceWorker] with ID: [10], PID: [13464], GUID: [1c1ac9c4-5315-11e5-8e34-b8e856479e14], status [started]...", :type=>"MiqWebServiceWorker"}]
[-] I 10:58:07.435318 #13413] : MIQ(MiqWebServiceWorker#terminate) Terminating Worker [MiqWebServiceWorker] with ID: [10], PID: [13464], GUID: [1c1ac9c4-5315-11e5-8e34-b8e856479e14], status [started]
[-] I 10:58:07.585393 #13464] : MIQ(MiqWebServiceWorker#log_status) [Web Services Worker] Worker ID [10], PID [13464], GUID [1c1ac9c4-5315-11e5-8e34-b8e856479e14], Last Heartbeat [2015-09-04 14:57:43 UTC], Process Info: Memory Usage [211869696], Memory Size [2769317888], Memory % [1.2], CPU Time [840.0], CPU % [0.0], Priority [31]
[-] I 10:58:07.585565 #13464] : MIQ(WebServiceWorker) ID [10] PID [13464] GUID [1c1ac9c4-5315-11e5-8e34-b8e856479e14] Exit request received. Worker exiting.
[-] I 10:58:08.440798 #13413] : MIQ(MiqServer#stop_worker) Stopping Worker [MiqGenericWorker] with ID: [3], PID: [13449], GUID: [1af9dab2-5315-11e5-8e34-b8e856479e14], status [started]...
[-] I 10:58:08.445609 #13413] : MIQ(MiqQueue.put) Message id: [36], id: [], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqEvent.raise_evm_event], Timeout: [600], Priority: [100], State: [ready], Deliver On: [], Data: [], Args: [["MiqServer", 3], "evm_worker_stop", {:event_details=>"Stopping Worker [MiqGenericWorker] with ID: [3], PID: [13449], GUID: [1af9dab2-5315-11e5-8e34-b8e856479e14], status [started]...", :type=>"MiqGenericWorker"}]
[-] I 10:58:08.447066 #13413] : MIQ(MiqServer#worker_set_message) Worker [MiqGenericWorker] with ID: [3], PID: [13449], GUID: [1af9dab2-5315-11e5-8e34-b8e856479e14] is being requested to exit
[-] I 10:58:08.447147 #13413] : MIQ(MiqServer#stop_worker) Stopping Worker [MiqReportingWorker] with ID: [7], PID: [13457], GUID: [1b4f11f8-5315-11e5-8e34-b8e856479e14], status [started]...
[-] I 10:58:08.452208 #13413] : MIQ(MiqQueue.put) Message id: [37], id: [], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqEvent.raise_evm_event], Timeout: [600], Priority: [100], State: [ready], Deliver On: [], Data: [], Args: [["MiqServer", 3], "evm_worker_stop", {:event_details=>"Stopping Worker [MiqReportingWorker] with ID: [7], PID: [13457], GUID: [1b4f11f8-5315-11e5-8e34-b8e856479e14], status [started]...", :type=>"MiqReportingWorker"}]
[-] I 10:58:08.454222 #13413] : MIQ(MiqServer#worker_set_message) Worker [MiqReportingWorker] with ID: [7], PID: [13457], GUID: [1b4f11f8-5315-11e5-8e34-b8e856479e14] is being requested to exit
[-] I 10:58:08.454334 #13413] : MIQ(MiqServer#stop_worker) Stopping Worker [MiqPriorityWorker] with ID: [4], PID: [13452], GUID: [1b1b246a-5315-11e5-8e34-b8e856479e14], status [started]...
[-] I 10:58:08.458752 #13413] : MIQ(MiqQueue.put) Message id: [38], id: [], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqEvent.raise_evm_event], Timeout: [600], Priority: [100], State: [ready], Deliver On: [], Data: [], Args: [["MiqServer", 3], "evm_worker_stop", {:event_details=>"Stopping Worker [MiqPriorityWorker] with ID: [4], PID: [13452], GUID: [1b1b246a-5315-11e5-8e34-b8e856479e14], status [started]...", :type=>"MiqPriorityWorker"}]
[-] I 10:58:08.460422 #13413] : MIQ(MiqServer#worker_set_message) Worker [MiqPriorityWorker] with ID: [4], PID: [13452], GUID: [1b1b246a-5315-11e5-8e34-b8e856479e14] is being requested to exit
[-] I 10:58:08.460531 #13413] : MIQ(MiqServer#stop_worker) Stopping Worker [MiqAutomateWorker] with ID: [11], PID: [13466], GUID: [1c5a0e36-5315-11e5-8e34-b8e856479e14], status [started]...
[-] I 10:58:08.464409 #13413] : MIQ(MiqQueue.put) Message id: [39], id: [], Zone: [default], Role: [], Server: [], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqEvent.raise_evm_event], Timeout: [600], Priority: [100], State: [ready], Deliver On: [], Data: [], Args: [["MiqServer", 3], "evm_worker_stop", {:event_details=>"Stopping Worker [MiqAutomateWorker] with ID: [11], PID: [13466], GUID: [1c5a0e36-5315-11e5-8e34-b8e856479e14], status [started]...", :type=>"MiqAutomateWorker"}]
[-] I 10:58:08.465769 #13413] : MIQ(MiqServer#worker_set_message) Worker [MiqAutomateWorker] with ID: [11], PID: [13466], GUID: [1c5a0e36-5315-11e5-8e34-b8e856479e14] is being requested to exit
[-] I 10:58:08.466893 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:08 UTC]...
[-] I 10:58:08.469269 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:08 UTC]...Complete
[-] I 10:58:08.471947 #13413] : MIQ(MiqServer#clean_worker_records) SQL Record for Worker [MiqUiWorker] with ID: [9], PID: [13462], GUID: [1bc08720-5315-11e5-8e34-b8e856479e14], Status: [stopped] is being deleted
[-] I 10:58:08.476897 #13413] : MIQ(MiqServer#clean_worker_records) SQL Record for Worker [MiqWebServiceWorker] with ID: [10], PID: [13464], GUID: [1c1ac9c4-5315-11e5-8e34-b8e856479e14], Status: [stopped] is being deleted
[-] I 10:58:10.539032 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:10 UTC]...
[-] I 10:58:10.542890 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:10 UTC]...Complete
[-] I 10:58:12.596319 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:12 UTC]...
[-] I 10:58:12.599989 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:12 UTC]...Complete
[-] I 10:58:14.657201 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:14 UTC]...
[-] I 10:58:14.660666 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:14 UTC]...Complete
[-] I 10:58:16.717331 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:16 UTC]...
[-] I 10:58:16.721559 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:16 UTC]...Complete
[-] I 10:58:17.089482 #13460] : MIQ(ScheduleWorker#do_work) Number of scheduled items to be processed: 1.
[-] I 10:58:17.095964 #13460] : MIQ(MiqQueue.put) Message id: [40], id: [], Zone: [default], Role: [], Server: [c69aab4c-4755-11e5-8436-b8e856479e14], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [Session.check_session_timeout], Timeout: [600], Priority: [90], State: [ready], Deliver On: [], Data: [], Args: []
[-] I 10:58:18.778336 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:18 UTC]...
[-] I 10:58:18.782327 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:18 UTC]...Complete
[-] I 10:58:20.833099 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:20 UTC]...
[-] I 10:58:20.837140 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:20 UTC]...Complete
[-] I 10:58:22.889204 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:22 UTC]...
[-] I 10:58:22.892948 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:22 UTC]...Complete
[-] I 10:58:24.941416 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:24 UTC]...
[-] I 10:58:24.945143 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:24 UTC]...Complete
[-] I 10:58:27.020522 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:27 UTC]...
[-] I 10:58:27.024884 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:27 UTC]...Complete
[-] I 10:58:29.083741 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:29 UTC]...
[-] I 10:58:29.088091 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:29 UTC]...Complete
[-] I 10:58:31.151109 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:31 UTC]...
[-] I 10:58:31.155590 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:31 UTC]...Complete
[-] I 10:58:32.099767 #13460] : MIQ(ScheduleWorker#do_work) Number of scheduled items to be processed: 1.
[-] I 10:58:33.206340 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:33 UTC]...
[-] I 10:58:33.210117 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:33 UTC]...Complete
[-] I 10:58:35.258306 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:35 UTC]...
[-] I 10:58:35.262152 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:35 UTC]...Complete
[-] I 10:58:37.314576 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:37 UTC]...
[-] I 10:58:37.318664 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:37 UTC]...Complete
[-] I 10:58:39.363729 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:39 UTC]...
[-] I 10:58:39.367587 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:39 UTC]...Complete
[-] I 10:58:41.418470 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:41 UTC]...
[-] I 10:58:41.422318 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:41 UTC]...Complete
[-] I 10:58:41.634986 #13446] : MIQ(MiqEventHandler#log_status) [Event Handler] Worker ID [1], PID [13446], GUID [1ad4ce02-5315-11e5-8e34-b8e856479e14], Last Heartbeat [2015-09-04 14:57:47 UTC], Process Info: Memory Usage [203108352], Memory Size [2764849152], Memory % [1.2], CPU Time [780.0], CPU % [0.0], Priority [31]
[-] I 10:58:41.635187 #13446] : MIQ(EventHandler) ID [1] PID [13446] GUID [1ad4ce02-5315-11e5-8e34-b8e856479e14] Exit request received. Worker exiting.
[-] I 10:58:42.535008 #13449] : MIQ(MiqGenericWorker#log_status) [Generic Worker] Worker ID [3], PID [13449], GUID [1af9dab2-5315-11e5-8e34-b8e856479e14], Last Heartbeat [2015-09-04 14:57:48 UTC], Process Info: Memory Usage [207847424], Memory Size [2760916992], Memory % [1.2], CPU Time [780.0], CPU % [0.0], Priority [31]
[-] I 10:58:42.535190 #13449] : MIQ(GenericWorker) ID [3] PID [13449] GUID [1af9dab2-5315-11e5-8e34-b8e856479e14] Exit request received. Worker exiting.
[-] I 10:58:42.574407 #13448] : MIQ(MiqGenericWorker#log_status) [Generic Worker] Worker ID [2], PID [13448], GUID [1af71d86-5315-11e5-8e34-b8e856479e14], Last Heartbeat [2015-09-04 14:57:48 UTC], Process Info: Memory Usage [206127104], Memory Size [2766159872], Memory % [1.2], CPU Time [780.0], CPU % [0.0], Priority [31]
[-] I 10:58:42.574595 #13448] : MIQ(GenericWorker) ID [2] PID [13448] GUID [1af71d86-5315-11e5-8e34-b8e856479e14] Exit request received. Worker exiting.
[-] I 10:58:43.269903 #13457] : MIQ(MiqReportingWorker#log_status) [Reporting Worker] Worker ID [7], PID [13457], GUID [1b4f11f8-5315-11e5-8e34-b8e856479e14], Last Heartbeat [2015-09-04 14:57:49 UTC], Process Info: Memory Usage [201076736], Memory Size [2763800576], Memory % [1.2], CPU Time [780.0], CPU % [1.7], Priority [31]
[-] I 10:58:43.270046 #13456] : MIQ(MiqReportingWorker#log_status) [Reporting Worker] Worker ID [6], PID [13456], GUID [1b49f6aa-5315-11e5-8e34-b8e856479e14], Last Heartbeat [2015-09-04 14:57:49 UTC], Process Info: Memory Usage [200691712], Memory Size [2755411968], Memory % [1.2], CPU Time [840.0], CPU % [0.7], Priority [31]
[-] I 10:58:43.270102 #13457] : MIQ(ReportingWorker) ID [7] PID [13457] GUID [1b4f11f8-5315-11e5-8e34-b8e856479e14] Exit request received. Worker exiting.
[-] I 10:58:43.270221 #13456] : MIQ(ReportingWorker) ID [6] PID [13456] GUID [1b49f6aa-5315-11e5-8e34-b8e856479e14] Exit request received. Worker exiting.
[-] I 10:58:43.463210 #13452] : MIQ(MiqPriorityWorker#log_status) [Priority Worker] Worker ID [4], PID [13452], GUID [1b1b246a-5315-11e5-8e34-b8e856479e14], Last Heartbeat [2015-09-04 14:57:50 UTC], Process Info: Memory Usage [201854976], Memory Size [2763014144], Memory % [1.2], CPU Time [840.0], CPU % [0.0], Priority [31]
[-] I 10:58:43.463406 #13452] : MIQ(PriorityWorker) ID [4] PID [13452] GUID [1b1b246a-5315-11e5-8e34-b8e856479e14] Exit request received. Worker exiting.
[-] I 10:58:43.463775 #13453] : MIQ(MiqPriorityWorker#log_status) [Priority Worker] Worker ID [5], PID [13453], GUID [1b1e67ba-5315-11e5-8e34-b8e856479e14], Last Heartbeat [2015-09-04 14:57:50 UTC], Process Info: Memory Usage [200572928], Memory Size [2754363392], Memory % [1.2], CPU Time [840.0], CPU % [0.0], Priority [31]
[-] I 10:58:43.463959 #13453] : MIQ(PriorityWorker) ID [5] PID [13453] GUID [1b1e67ba-5315-11e5-8e34-b8e856479e14] Exit request received. Worker exiting.
[-] I 10:58:43.471041 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:43 UTC]...
[-] I 10:58:43.473559 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:43 UTC]...Complete
[-] I 10:58:43.475654 #13413] : MIQ(MiqServer#clean_worker_records) SQL Record for Worker [MiqEventHandler] with ID: [1], PID: [13446], GUID: [1ad4ce02-5315-11e5-8e34-b8e856479e14], Status: [stopped] is being deleted
[-] I 10:58:43.479224 #13413] : MIQ(MiqServer#clean_worker_records) SQL Record for Worker [MiqGenericWorker] with ID: [2], PID: [13448], GUID: [1af71d86-5315-11e5-8e34-b8e856479e14], Status: [stopped] is being deleted
[-] I 10:58:43.481764 #13413] : MIQ(MiqServer#clean_worker_records) SQL Record for Worker [MiqGenericWorker] with ID: [3], PID: [13449], GUID: [1af9dab2-5315-11e5-8e34-b8e856479e14], Status: [stopped] is being deleted
[-] I 10:58:43.485076 #13413] : MIQ(MiqServer#clean_worker_records) SQL Record for Worker [MiqPriorityWorker] with ID: [4], PID: [13452], GUID: [1b1b246a-5315-11e5-8e34-b8e856479e14], Status: [stopped] is being deleted
[-] I 10:58:43.487791 #13413] : MIQ(MiqServer#clean_worker_records) SQL Record for Worker [MiqPriorityWorker] with ID: [5], PID: [13453], GUID: [1b1e67ba-5315-11e5-8e34-b8e856479e14], Status: [stopped] is being deleted
[-] I 10:58:43.491401 #13413] : MIQ(MiqServer#clean_worker_records) SQL Record for Worker [MiqReportingWorker] with ID: [7], PID: [13457], GUID: [1b4f11f8-5315-11e5-8e34-b8e856479e14], Status: [stopped] is being deleted
[-] I 10:58:43.493813 #13413] : MIQ(MiqServer#clean_worker_records) SQL Record for Worker [MiqReportingWorker] with ID: [6], PID: [13456], GUID: [1b49f6aa-5315-11e5-8e34-b8e856479e14], Status: [stopped] is being deleted
[-] I 10:58:44.251327 #13466] : MIQ(MiqAutomateWorker#log_status) [Automate Worker] Worker ID [11], PID [13466], GUID [1c5a0e36-5315-11e5-8e34-b8e856479e14], Last Heartbeat [2015-09-04 14:57:50 UTC], Process Info: Memory Usage [204517376], Memory Size [2757509120], Memory % [1.2], CPU Time [780.0], CPU % [0.0], Priority [31]
[-] I 10:58:44.251507 #13466] : MIQ(AutomateWorker) ID [11] PID [13466] GUID [1c5a0e36-5315-11e5-8e34-b8e856479e14] Exit request received. Worker exiting.
[-] I 10:58:44.332458 #13467] : MIQ(MiqAutomateWorker#log_status) [Automate Worker] Worker ID [12], PID [13467], GUID [1c5e7804-5315-11e5-8e34-b8e856479e14], Last Heartbeat [2015-09-04 14:57:50 UTC], Process Info: Memory Usage [204693504], Memory Size [2765897728], Memory % [1.2], CPU Time [780.0], CPU % [0.0], Priority [31]
[-] I 10:58:44.332632 #13467] : MIQ(AutomateWorker) ID [12] PID [13467] GUID [1c5e7804-5315-11e5-8e34-b8e856479e14] Exit request received. Worker exiting.
[-] I 10:58:45.517427 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:45 UTC]...
[-] I 10:58:45.521310 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:45 UTC]...Complete
[-] I 10:58:45.523584 #13413] : MIQ(MiqServer#clean_worker_records) SQL Record for Worker [MiqAutomateWorker] with ID: [11], PID: [13466], GUID: [1c5a0e36-5315-11e5-8e34-b8e856479e14], Status: [stopped] is being deleted
[-] I 10:58:45.526223 #13413] : MIQ(MiqServer#clean_worker_records) SQL Record for Worker [MiqAutomateWorker] with ID: [12], PID: [13467], GUID: [1c5e7804-5315-11e5-8e34-b8e856479e14], Status: [stopped] is being deleted
[-] I 10:58:47.127162 #13460] : MIQ(MiqScheduleWorker#log_status) [Schedule Worker] Worker ID [8], PID [13460], GUID [1b8c860a-5315-11e5-8e34-b8e856479e14], Last Heartbeat [2015-09-04 14:57:47 UTC], Process Info: Memory Usage [204599296], Memory Size [2767269888], Memory % [1.2], CPU Time [840.0], CPU % [0.1], Priority [31]
[-] I 10:58:47.127348 #13460] : MIQ(ScheduleWorker) ID [8] PID [13460] GUID [1b8c860a-5315-11e5-8e34-b8e856479e14] Exit request received. Worker exiting.
[-] I 10:58:47.538010 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:47 UTC]...
[-] I 10:58:47.541801 #13413] : MIQ(MiqServer#heartbeat) Heartbeat [2015-09-04 14:58:47 UTC]...Complete
[-] I 10:58:47.543790 #13413] : MIQ(MiqServer#clean_worker_records) SQL Record for Worker [MiqScheduleWorker] with ID: [8], PID: [13460], GUID: [1b8c860a-5315-11e5-8e34-b8e856479e14], Status: [stopped] is being deleted
[-] I 10:58:47.547828 #13413] : MIQ(MiqServer#quiesce_all_workers) Cleaning all active messages being processed by MiqServer
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment