[Solved] Problem with new EMS Cloud


#1

Good mornign,
I have a problem when add a new Ems Cloud.
Today I have add two Ems Cloud Openstack (Havana and Juno), after validate of credentials and add Ems Cloud, in relationships on summary I see all information at zero, I don’t see my openstack features.

Is there a solution??

Thank you
Dario


#2

This will prolly take debug output to troubleshoot. In the UI go to configure/configuration/ , select the ManageIQ appliance that is in the Openstack Zone and go to Advanced.
Find the folllowing line and make the change bellow.

level_fog: info

to

level_fog: debug

Allow a few minutes to pass and then issue a refresh relationships and power states for the openstack env. Find the /var/www/miq/vmdb/log/fog.log and locate the debug errors. Please provide them to the thread.


#3

this is the error in fog.log

[----] D, [2015-07-10T01:58:08.036525 #1049:955e98] DEBUG – : excon.request
{:uri=>“http://192.168.0.4:9292/”,
:method=>“GET”,
:headers=>
{“User-Agent”=>“fog/1.28.0 fog-core/1.30.0”,
“Content-Type”=>“application/json”,
“Accept”=>“application/json”,
“X-Auth-Token”=>"[edit by sixart]",
“Host”=>“192.168.0.4:9292”},
:body=>nil}

[----] E, [2015-07-10T01:59:08.126372 #1049:955e98] ERROR – : excon.error #<Excon::Errors::Timeout: connect timeout reached>

I don’t found a solution


#4

Can the manageIQ appliance reach this endpoint for glance or is it on a private network?
{:uri=>“http://192.168.0.4:9292/”,


#5

My ManageIQ Address is 10.170.10.136
and my OpenStack Address is 10.170.10.4.
The Address Api Access for Image is 10.170.10.4:9292.

Address 192.168.0.4 for me is a mystery, i don’t know where to take it


#6

Manageiq uses both the pubicurl and the adminurl endpoints from openstack.

On the openstack system check your endpoints for each service.

keystone endpoint-list


#7

The address 192.168.0.4 is adminurl.

Buf, if I connect ManageIQ with OpenStack environment locate in another network, how can ManageIQ connect with this network??? This network is the management network (with GRE) in OpenStack environment


[Solved] Excon::Errors::Timeout
#8

Try limiting cloudforms to use only PublicURL, First take backup of "var/www/miq/lib/openstack/openstack_handle/handle.rb file and then in original file specify which endpoint type should be used by adding :openstack_endpoint_type => ‘publicURL’ in the opts for self.raw_connect definition.

Extract from the code:

def self.raw_connect(username, password, auth_url, service = “Compute”, extra_opts = nil)
opts = {
:provider => ‘OpenStack’,
:openstack_auth_url => auth_url,
:openstack_username => username,
:openstack_api_key => password,
:openstack_endpoint_type => ‘publicURL’,
}
opts.merge!(extra_opts) if extra_opts

Save the file, Wait for few minutes and then do evm refresh…


#9

I change the file, and I don’t found error in fog.log.
But, in Cloud -> Summary of Web Interface I found this error
"undefined method `truncate’ for nil:NilClass"

How can I fix it???


#10

Does [Solved] Excon::Errors::Timeout or Openstack credential failed answer your question or give you more info?

@blomquisg See the comment above with a possible fix for the OpenStack handle code.


#11

Very interesting! I’ll point @Ladas this way and see if we can use that to completely eliminate the rogue 401s in the logs.

This could be a huge help @eprsaad! Thanks for the feedback


GregB


#12

I resolv problem with connection at 192.168…

but, I have another problem, when i Add a Ems Cloud, in a Cloud Summary found this error “undefined method `truncate’ for nil:NilClass”

I don’t fix it, can you help me??


#13

@SixArt could you check also ems.log ? I am not sure where this error originates, would be nice to have full error log.


#14

Sorry for this long time of silent,
I resolve the problem. I modify file ""var/www/miq/lib/openstack/openstack_handle/handle.rb"and go on.

The problem "“undefined method `truncate’ for nil:NilClass” is because I set wrong password for acqp.

Dario


#15

Hi SixArt,

I’m dealing with the same problem here.

I have an OpenStack Havana I’m trying to add to my ManageIQ appliance for vSphere as an EMS Cloud OpenStack. After adding the EMS, I can see that all information is set to zero. It looks like no data was retrieved.

Default user and AMQP user get validated, and with logs set to debug, I can see in the fog.log that ManageIQ sees the correct OpenStack Keystone Project. Moreover, I made sure that all endpoints were accessible from the ManageIQ instance.

The thing is that I see the same error you see in the Last Refresh field, inside the Summary section of ManageIQ portal:

undefined method `truncate’ for nil:NilClass

Could you please tell me what did you exactly do in order to solve this problem?
I didn’t understand what did you do.

Thank you in advance.

Regards,
Alex.


#16

Hello,

Could anybody help me with this issue?

Many thanks.

Regards,
Alex.


#17

Hi @Alex, @SixArt was saying that he had missing credentials for (I think) amqp. Are your credentials set? Otherwise can you get the stacktrace out of the log/evm.log? That might help us narrow down what’s going on.


#18

Hi Fryguy,

As I mentioned before, AMQP user gets validated and credentials are set.
However, when I do a refresh, no information is retrieved and the error I get doesn’t help.

[----] I, [2015-07-27T15:41:52.889814 #8086:3b1e88]  INFO -- : Q-task_id([job_dispatcher]) MIQ(JobProxyDispatcher-dispatch) Complete - Timings: {:pending_jobs=>0.0004303455352783203, :jobs_to_dispatch_count=>0, :total_time=>0.0016782283782958984}
[----] I, [2015-07-27T15:41:52.890152 #8086:3b1e88]  INFO -- : Q-task_id([job_dispatcher]) MIQ(MiqQueue.delivered)  Message id: [54388], State: [ok], Delivered in [0.002293901] seconds
[----] I, [2015-07-27T15:41:53.716847 #8078:899e8c]  INFO -- : MIQ(MiqQueue.get_via_drb) Message id: [54386], MiqWorker id: [17], 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.950844502] seconds
[----] I, [2015-07-27T15:41:53.717000 #8078:899e8c]  INFO -- : MIQ(MiqQueue.deliver)    Message id: [54386], Delivering...
[----] D, [2015-07-27T15:41:53.717270 #8078:899e8c] DEBUG -- : Checking for timed out jobs
[----] I, [2015-07-27T15:41:53.720888 #8078:899e8c]  INFO -- : MIQ(MiqQueue.delivered)  Message id: [54386], State: [ok], Delivered in [0.003849629] seconds
[----] I, [2015-07-27T15:41:53.731479 #8078:899e8c]  INFO -- : MIQ(MiqQueue.get_via_drb) Message id: [54387], MiqWorker id: [17], Zone: [default], Role: [], Server: [7f9e50a4-3116-11e5-8427-005056920a80], 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.960073867] seconds
[----] I, [2015-07-27T15:41:53.731610 #8078:899e8c]  INFO -- : MIQ(MiqQueue.deliver)    Message id: [54387], Delivering...
[----] D, [2015-07-27T15:41:53.731824 #8078:899e8c] DEBUG -- : Checking session data
[----] I, [2015-07-27T15:41:53.740658 #8078:899e8c]  INFO -- : MIQ(MiqQueue.delivered)  Message id: [54387], State: [ok], Delivered in [0.009016774] seconds
[----] D, [2015-07-27T15:42:01.083240 #8100:9fde90] DEBUG -- : Role Authorization successful for: userid [admin], role id [1], feature identifier [ems_cloud_refresh]
[----] D, [2015-07-27T15:42:01.085359 #8100:9fde90] DEBUG -- : Role Authorization successful for: userid [admin], role id [1], feature identifier [ems_cloud_refresh]
[----] I, [2015-07-27T15:42:01.099865 #8100:9fde90]  INFO -- : MIQ(MiqQueue.put)        Message id: [54389],  id: [], Zone: [default], Role: [ems_inventory], Server: [], Ident: [ems_2], Target id: [], Instance id: [], Task id: [], Command: [EmsRefresh.refresh], Timeout: [7200], Priority: [100], State: [ready], Deliver On: [], Data: [], Args: [[["EmsOpenstack", 2]]]
[----] D, [2015-07-27T15:42:01.101378 #8100:9fde90] DEBUG -- : MIQ(ems_cloud_controller-button): Refresh Cloud Providers initiated for 1 Cloud Provider from the CFME Database
[----] I, [2015-07-27T15:42:01.105957 #8100:9fde90]  INFO -- : <AuditSuccess> MIQ(EmsCommon.process_emss) userid: [admin] - 'refresh_ems' successfully initiated for 1 Cloud Providers
[----] D, [2015-07-27T15:42:01.116840 #8100:9fde90] DEBUG -- : MIQ(RBAC.search): Find options: {:conditions=>"(ext_management_systems.id = 2)", :include=>{}, :order=>nil, :limit=>nil, :offset=>nil}
[----] D, [2015-07-27T15:42:01.133532 #8100:9fde90] DEBUG -- : MIQ(RBAC.search): Find options: {:conditions=>"(ext_management_systems.id = 2)", :include=>{}, :order=>nil, :limit=>nil, :offset=>nil}
[----] I, [2015-07-27T15:42:01.952515 #5285:769e90]  INFO -- : MIQ(MiqServer.populate_queue_messages) Fetched 1 miq_queue rows for queue_name=ems_2, wcount=2, priority=200
[----] I, [2015-07-27T15:42:03.788491 #8096:6b3e88]  INFO -- : MIQ(ScheduleWorker.do_work) Number of scheduled items to be processed: 1.
[----] I, [2015-07-27T15:42:03.796258 #8096:6b3e88]  INFO -- : MIQ(MiqQueue.put)        Message id: [54390],  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, [2015-07-27T15:42:04.126077 #9374:79be90]  INFO -- : MIQ(EventCatcherOpenstack) EMS [10.12.12.11] as [anunez] Event Monitor Thread gone. Restarting...
[----] I, [2015-07-27T15:42:04.126500 #9374:79be90]  INFO -- : MIQ(EventCatcherOpenstack) EMS [10.12.12.11] as [anunez] Validating Connection/Credentials
[----] I, [2015-07-27T15:42:04.126648 #9374:79be90]  INFO -- : MIQ(EmsOpenstack.with_provider_connection) Connecting through EmsOpenstack: [OpenStack Dev Cloud]
[----] I, [2015-07-27T15:42:04.126903 #9374:79be90]  INFO -- : MIQ(EventCatcherOpenstack) EMS [10.12.12.11] as [anunez] Starting Event Monitor Thread
[----] I, [2015-07-27T15:42:04.127066 #9374:79be90]  INFO -- : MIQ(EventCatcherOpenstack) EMS [10.12.12.11] as [anunez] Started Event Monitor Thread
[----] I, [2015-07-27T15:42:06.953125 #5285:769e90]  INFO -- : MIQ(MiqServer.heartbeat) Heartbeat [2015-07-27 13:42:06 UTC]...
[----] I, [2015-07-27T15:42:06.960373 #5285:769e90]  INFO -- : MIQ(MiqServer.heartbeat) Heartbeat [2015-07-27 13:42:06 UTC]...Complete
[----] D, [2015-07-27T15:42:06.965899 #5285:769e90] DEBUG -- : MIQ(MiqServer.monitor_servers_as_master) Checking other servers as master server
[----] D, [2015-07-27T15:42:06.969208 #5285:769e90] DEBUG -- : MIQ(MiqRegion#lock) Acquiring lock on MiqRegion::1...
[----] D, [2015-07-27T15:42:06.970166 #5285:769e90] DEBUG -- : MIQ(MiqRegion#lock) Acquired lock
[----] D, [2015-07-27T15:42:07.000371 #5285:769e90] DEBUG -- : MIQ(MiqRegion#lock) Releasing lock
[----] D, [2015-07-27T15:42:07.232170 #5285:769e90] DEBUG -- : MIQ(MiqServer) Invoke algorithm started with options: [{:name=>:used_swap_percent_gt_value, :value=>80, :type=>:kill}]
[----] D, [2015-07-27T15:42:07.232369 #5285:769e90] DEBUG -- : MIQ(MiqServer) Executing [kill] algorithm: [used_swap_percent_gt_value]
[----] D, [2015-07-27T15:42:07.232811 #5285:769e90] DEBUG -- : MIQ(MiqServer) Executing [kill] algorithm: [used_swap_percent_gt_value] completed with result: [false]
[----] I, [2015-07-27T15:42:07.237366 #5285:769e90]  INFO -- : MIQ(MiqServer.populate_queue_messages) Fetched 1 miq_queue rows for queue_name=generic, wcount=4, priority=200
[----] I, [2015-07-27T15:42:07.240039 #5285:769e90]  INFO -- : MIQ(MiqServer.populate_queue_messages) Fetched 1 miq_queue rows for queue_name=ems_2, wcount=2, priority=200
[----] I, [2015-07-27T15:42:07.791700 #19623:b69e8c]  INFO -- : MIQ(MiqQueue.get_via_drb) Message id: [54389], MiqWorker id: [75], Zone: [default], Role: [ems_inventory], Server: [], Ident: [ems_2], Target id: [], Instance id: [], Task id: [], Command: [EmsRefresh.refresh], Timeout: [7200], Priority: [100], State: [dequeue], Deliver On: [], Data: [], Args: [[["EmsOpenstack", 2]]], Dequeued in: [6.696631869] seconds
[----] I, [2015-07-27T15:42:07.791939 #19623:b69e8c]  INFO -- : MIQ(MiqQueue.deliver)    Message id: [54389], Delivering...
[----] I, [2015-07-27T15:42:07.795357 #19623:b69e8c]  INFO -- : MIQ(EmsRefresh::Refreshers::OpenstackRefresher.refresh) Refreshing all targets...
[----] I, [2015-07-27T15:42:07.795549 #19623:b69e8c]  INFO -- : MIQ(EmsRefresh::Refreshers::OpenstackRefresher.refresh) EMS: [OpenStack Dev Cloud], id: [2] Refreshing targets for EMS: [OpenStack Dev Cloud], id: [2]...
[----] I, [2015-07-27T15:42:07.795701 #19623:b69e8c]  INFO -- : MIQ(EmsRefresh::Refreshers::OpenstackRefresher.refresh) EMS: [OpenStack Dev Cloud], id: [2]   EmsOpenstack [OpenStack Dev Cloud] id [2]
[----] D, [2015-07-27T15:42:07.795844 #19623:b69e8c] DEBUG -- : MIQ(EmsRefresh::Refreshers::OpenstackRefresher.refresh) EMS: [OpenStack Dev Cloud], id: [2] Parsing Openstack inventory...
[----] I, [2015-07-27T15:42:08.076108 #8086:3b1e88]  INFO -- : MIQ(MiqQueue.get_via_drb) Message id: [54390], MiqWorker id: [19], 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.283298378] seconds
[----] I, [2015-07-27T15:42:08.076321 #8086:3b1e88]  INFO -- : Q-task_id([job_dispatcher]) MIQ(MiqQueue.deliver)    Message id: [54390], Delivering...
[----] I, [2015-07-27T15:42:08.078769 #8086:3b1e88]  INFO -- : Q-task_id([job_dispatcher]) MIQ(JobProxyDispatcher-dispatch) Complete - Timings: {:pending_jobs=>0.0006175041198730469, :jobs_to_dispatch_count=>0, :total_time=>0.0021300315856933594}
[----] I, [2015-07-27T15:42:08.079268 #8086:3b1e88]  INFO -- : Q-task_id([job_dispatcher]) MIQ(MiqQueue.delivered)  Message id: [54390], State: [ok], Delivered in [0.002936103] seconds
[----] E, [2015-07-27T15:42:17.030825 #19623:b69e8c] ERROR -- : MIQ(EmsRefresh::Refreshers::OpenstackRefresher.refresh) EMS: [OpenStack Dev Cloud], id: [2] Refresh failed
[----] E, [2015-07-27T15:42:17.031178 #19623:b69e8c] ERROR -- : [NoMethodError]: undefined method `truncate' for nil:NilClass  Method:[rescue in block in refresh]
[----] E, [2015-07-27T15:42:17.031361 #19623:b69e8c] ERROR -- : /var/www/miq/vmdb/app/models/ems_refresh/parsers/cloud.rb:24:in `parse_security_group'
/var/www/miq/vmdb/app/models/ems_refresh/parsers/openstack.rb:323:in `parse_security_group'
/var/www/miq/vmdb/app/models/ems_refresh/parsers/openstack.rb:119:in `block in get_security_groups'
/var/www/miq/vmdb/app/models/ems_refresh/parsers/openstack.rb:183:in `process_collection_item'
/var/www/miq/vmdb/app/models/ems_refresh/parsers/openstack.rb:177:in `block in process_collection'
/var/www/miq/vmdb/app/models/ems_refresh/parsers/openstack.rb:177:in `each'
/var/www/miq/vmdb/app/models/ems_refresh/parsers/openstack.rb:177:in `process_collection'
/var/www/miq/vmdb/app/models/ems_refresh/parsers/openstack.rb:119:in `get_security_groups'
/var/www/miq/vmdb/app/models/ems_refresh/parsers/openstack.rb:43:in `ems_inv_to_hashes'
/var/www/miq/vmdb/app/models/ems_refresh/parsers/openstack.rb:9:in `ems_inv_to_hashes'
/var/www/miq/vmdb/app/models/ems_refresh/refreshers/openstack_refresher.rb:6:in `parse_inventory'
/var/www/miq/vmdb/app/models/ems_refresh/refreshers/ems_refresher_mixin.rb:20:in `block in refresh'
/var/www/miq/vmdb/app/models/ems_refresh/refreshers/ems_refresher_mixin.rb:8:in `each'
/var/www/miq/vmdb/app/models/ems_refresh/refreshers/ems_refresher_mixin.rb:8:in `refresh'
/var/www/miq/vmdb/app/models/ems_refresh/refreshers/base_refresher.rb:8:in `refresh'
/var/www/miq/vmdb/app/models/ems_refresh.rb:80:in `block in refresh'
/var/www/miq/vmdb/app/models/ems_refresh.rb:78:in `each'
/var/www/miq/vmdb/app/models/ems_refresh.rb:78:in `refresh'
/var/www/miq/vmdb/app/models/miq_queue.rb:356:in `block in deliver'
/opt/rubies/ruby-2.0.0-p645/lib/ruby/2.0.0/timeout.rb:66:in `timeout'
/var/www/miq/vmdb/app/models/miq_queue.rb:352:in `deliver'
/var/www/miq/vmdb/lib/workers/queue_worker_base.rb:107:in `deliver_queue_message'
/var/www/miq/vmdb/lib/workers/queue_worker_base.rb:135:in `deliver_message'
/var/www/miq/vmdb/lib/workers/queue_worker_base.rb:152:in `block in do_work'
/var/www/miq/vmdb/lib/workers/queue_worker_base.rb:146:in `loop'
/var/www/miq/vmdb/lib/workers/queue_worker_base.rb:146:in `do_work'
/var/www/miq/vmdb/lib/workers/worker_base.rb:323:in `block in do_work_loop'
/var/www/miq/vmdb/lib/workers/worker_base.rb:320:in `loop'
/var/www/miq/vmdb/lib/workers/worker_base.rb:320:in `do_work_loop'
/var/www/miq/vmdb/lib/workers/worker_base.rb:141:in `run'
/var/www/miq/vmdb/lib/workers/worker_base.rb:122:in `start'
/var/www/miq/vmdb/lib/workers/worker_base.rb:23:in `start_worker'
/var/www/miq/vmdb/lib/workers/bin/worker.rb:3:in `<top (required)>'
/opt/rubies/ruby-2.0.0-p645/lib/ruby/gems/2.0.0/bundler/gems/rails-4842a8377644/railties/lib/rails/commands/runner.rb:52:in `eval'
/opt/rubies/ruby-2.0.0-p645/lib/ruby/gems/2.0.0/bundler/gems/rails-4842a8377644/railties/lib/rails/commands/runner.rb:52:in `<top (required)>'
/opt/rubies/ruby-2.0.0-p645/lib/ruby/gems/2.0.0/bundler/gems/rails-4842a8377644/railties/lib/rails/commands.rb:64:in `require'
/opt/rubies/ruby-2.0.0-p645/lib/ruby/gems/2.0.0/bundler/gems/rails-4842a8377644/railties/lib/rails/commands.rb:64:in `<top (required)>'
script/rails:6:in `require'
script/rails:6:in `<main>'
[----] E, [2015-07-27T15:42:17.031480 #19623:b69e8c] ERROR -- : MIQ(EmsRefresh::Refreshers::OpenstackRefresher.refresh) EMS: [OpenStack Dev Cloud], id: [2] Unable to perform refresh for the following targets:
[----] E, [2015-07-27T15:42:17.031685 #19623:b69e8c] ERROR -- :  --- EmsOpenstack [OpenStack Dev Cloud] id [2]
[----] I, [2015-07-27T15:42:17.042568 #19623:b69e8c]  INFO -- : MIQ(EmsRefresh::Refreshers::OpenstackRefresher.refresh) Refreshing all targets...Complete
[----] I, [2015-07-27T15:42:17.043253 #19623:b69e8c]  INFO -- : MIQ(MiqQueue.delivered)  Message id: [54389], State: [ok], Delivered in [9.251299157] seconds
[----] I, [2015-07-27T15:42:18.804490 #8096:6b3e88]  INFO -- : MIQ(ScheduleWorker.do_work) Number of scheduled items to be processed: 2.
[----] I, [2015-07-27T15:42:18.810543 #8096:6b3e88]  INFO -- : MIQ(MiqQueue.put)        Message id: [54391],  id: [], Zone: [default], Role: [], Server: [7f9e50a4-3116-11e5-8427-005056920a80], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [Session.check_session_timeout], Timeout: [600], Priority: [90], State: [ready], Deliver On: [], Data: [], Args: []
[----] I, [2015-07-27T15:42:18.817002 #8096:6b3e88]  INFO -- : MIQ(MiqQueue.put)        Message id: [54392],  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, [2015-07-27T15:42:19.127852 #9374:79be90]  INFO -- : MIQ(EventCatcherOpenstack) EMS [10.12.12.11] as [anunez] Event Monitor Thread gone. Restarting...
[----] I, [2015-07-27T15:42:19.128072 #9374:79be90]  INFO -- : MIQ(EventCatcherOpenstack) EMS [10.12.12.11] as [anunez] Validating Connection/Credentials
[----] I, [2015-07-27T15:42:19.128203 #9374:79be90]  INFO -- : MIQ(EmsOpenstack.with_provider_connection) Connecting through EmsOpenstack: [OpenStack Dev Cloud]
[----] I, [2015-07-27T15:42:19.128446 #9374:79be90]  INFO -- : MIQ(EventCatcherOpenstack) EMS [10.12.12.11] as [anunez] Starting Event Monitor Thread
[----] I, [2015-07-27T15:42:19.128595 #9374:79be90]  INFO -- : MIQ(EventCatcherOpenstack) EMS [10.12.12.11] as [anunez] Started Event Monitor Thread
[----] D, [2015-07-27T15:42:22.481838 #5285:769e90] DEBUG -- : MIQ(MiqServer) Invoke algorithm started with options: [{:name=>:used_swap_percent_gt_value, :value=>80, :type=>:kill}]
[----] D, [2015-07-27T15:42:22.482052 #5285:769e90] DEBUG -- : MIQ(MiqServer) Executing [kill] algorithm: [used_swap_percent_gt_value]
[----] D, [2015-07-27T15:42:22.482482 #5285:769e90] DEBUG -- : MIQ(MiqServer) Executing [kill] algorithm: [used_swap_percent_gt_value] completed with result: [false]
[----] I, [2015-07-27T15:42:22.487093 #5285:769e90]  INFO -- : MIQ(MiqServer.populate_queue_messages) Fetched 2 miq_queue rows for queue_name=generic, wcount=4, priority=200
[----] I, [2015-07-27T15:42:23.124274 #8082:131be8c]  INFO -- : MIQ(MiqQueue.get_via_drb) Message id: [54392], MiqWorker id: [18], 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.310113382] seconds
[----] I, [2015-07-27T15:42:23.124500 #8082:131be8c]  INFO -- : Q-task_id([job_dispatcher]) MIQ(MiqQueue.deliver)    Message id: [54392], Delivering...
[----] I, [2015-07-27T15:42:23.127171 #8082:131be8c]  INFO -- : Q-task_id([job_dispatcher]) MIQ(JobProxyDispatcher-dispatch) Complete - Timings: {:pending_jobs=>0.0006780624389648438, :jobs_to_dispatch_count=>0, :total_time=>0.0022263526916503906}
[----] I, [2015-07-27T15:42:23.127647 #8082:131be8c]  INFO -- : Q-task_id([job_dispatcher]) MIQ(MiqQueue.delivered)  Message id: [54392], State: [ok], Delivered in [0.003141238] seconds
[----] I, [2015-07-27T15:42:23.788343 #8078:899e8c]  INFO -- : MIQ(MiqQueue.get_via_drb) Message id: [54391], MiqWorker id: [17], Zone: [default], Role: [], Server: [7f9e50a4-3116-11e5-8427-005056920a80], 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.98077802] seconds
[----] I, [2015-07-27T15:42:23.788544 #8078:899e8c]  INFO -- : MIQ(MiqQueue.deliver)    Message id: [54391], Delivering...
[----] D, [2015-07-27T15:42:23.788839 #8078:899e8c] DEBUG -- : Checking session data
[----] I, [2015-07-27T15:42:23.798825 #8078:899e8c]  INFO -- : MIQ(MiqQueue.delivered)  Message id: [54391], State: [ok], Delivered in [0.010270415] seconds
[----] I, [2015-07-27T15:42:33.822765 #8096:6b3e88]  INFO -- : MIQ(ScheduleWorker.do_work) Number of scheduled items to be processed: 1.
[----] I, [2015-07-27T15:42:33.830051 #8096:6b3e88]  INFO -- : MIQ(MiqQueue.put)        Message id: [54393],  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, [2015-07-27T15:42:34.131693 #9374:79be90]  INFO -- : MIQ(EventCatcherOpenstack) EMS [10.12.12.11] as [anunez] Event Monitor Thread gone. Restarting...
[----] I, [2015-07-27T15:42:34.131922 #9374:79be90]  INFO -- : MIQ(EventCatcherOpenstack) EMS [10.12.12.11] as [anunez] Validating Connection/Credentials
[----] I, [2015-07-27T15:42:34.132054 #9374:79be90]  INFO -- : MIQ(EmsOpenstack.with_provider_connection) Connecting through EmsOpenstack: [OpenStack Dev Cloud]
[----] I, [2015-07-27T15:42:34.132288 #9374:79be90]  INFO -- : MIQ(EventCatcherOpenstack) EMS [10.12.12.11] as [anunez] Starting Event Monitor Thread
[----] I, [2015-07-27T15:42:34.132459 #9374:79be90]  INFO -- : MIQ(EventCatcherOpenstack) EMS [10.12.12.11] as [anunez] Started Event Monitor Thread
[----] I, [2015-07-27T15:42:37.508761 #5285:769e90]  INFO -- : MIQ(MiqServer.heartbeat) Heartbeat [2015-07-27 13:42:37 UTC]...
[----] I, [2015-07-27T15:42:37.515607 #5285:769e90]  INFO -- : MIQ(MiqServer.heartbeat) Heartbeat [2015-07-27 13:42:37 UTC]...Complete
[----] D, [2015-07-27T15:42:37.900857 #5285:769e90] DEBUG -- : MIQ(MiqServer) Invoke algorithm started with options: [{:name=>:used_swap_percent_gt_value, :value=>80, :type=>:kill}]
[----] D, [2015-07-27T15:42:37.901056 #5285:769e90] DEBUG -- : MIQ(MiqServer) Executing [kill] algorithm: [used_swap_percent_gt_value]
[----] D, [2015-07-27T15:42:37.901643 #5285:769e90] DEBUG -- : MIQ(MiqServer) Executing [kill] algorithm: [used_swap_percent_gt_value] completed with result: [false]
[----] I, [2015-07-27T15:42:37.906505 #5285:769e90]  INFO -- : MIQ(MiqServer.populate_queue_messages) Fetched 1 miq_queue rows for queue_name=generic, wcount=4, priority=200
[----] I, [2015-07-27T15:42:38.178763 #8082:131be8c]  INFO -- : MIQ(MiqQueue.get_via_drb) Message id: [54393], MiqWorker id: [18], 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.351783635] seconds
[----] I, [2015-07-27T15:42:38.178937 #8082:131be8c]  INFO -- : Q-task_id([job_dispatcher]) MIQ(MiqQueue.deliver)    Message id: [54393], Delivering...
[----] I, [2015-07-27T15:42:38.181279 #8082:131be8c]  INFO -- : Q-task_id([job_dispatcher]) MIQ(JobProxyDispatcher-dispatch) Complete - Timings: {:pending_jobs=>0.0005888938903808594, :jobs_to_dispatch_count=>0, :total_time=>0.0020265579223632812}
[----] I, [2015-07-27T15:42:38.181692 #8082:131be8c]  INFO -- : Q-task_id([job_dispatcher]) MIQ(MiqQueue.delivered)  Message id: [54393], State: [ok], Delivered in [0.002746277] seconds
[----] I, [2015-07-27T15:42:48.836537 #8096:6b3e88]  INFO -- : MIQ(ScheduleWorker.do_work) Number of scheduled items to be processed: 5.
[----] I, [2015-07-27T15:42:48.842696 #8096:6b3e88]  INFO -- : MIQ(MiqQueue.put)        Message id: [54394],  id: [], Zone: [default], Role: [], Server: [7f9e50a4-3116-11e5-8427-005056920a80], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [MiqServer.status_update], Timeout: [600], Priority: [20], State: [ready], Deliver On: [], Data: [], Args: []
[----] I, [2015-07-27T15:42:48.850241 #8096:6b3e88]  INFO -- : MIQ(MiqQueue.put)        Message id: [54395],  id: [], Zone: [default], Role: [], Server: [7f9e50a4-3116-11e5-8427-005056920a80], Ident: [generic], Target id: [], Instance id: [], Task id: [], Command: [Session.check_session_timeout], Timeout: [600], Priority: [90], State: [ready], Deliver On: [], Data: [], Args: []
[----] I, [2015-07-27T15:42:48.858840 #8096:6b3e88]  INFO -- : MIQ(MiqQueue.put)        Message id: [54396],  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, [2015-07-27T15:42:48.865802 #8096:6b3e88]  INFO -- : MIQ(MiqQueue.put)        Message id: [54397],  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, [2015-07-27T15:42:49.133236 #9374:79be90]  INFO -- : MIQ(EventCatcherOpenstack) EMS [10.12.12.11] as [anunez] Event Monitor Thread gone. Restarting...
[----] I, [2015-07-27T15:42:49.133493 #9374:79be90]  INFO -- : MIQ(EventCatcherOpenstack) EMS [10.12.12.11] as [anunez] Validating Connection/Credentials
[----] I, [2015-07-27T15:42:49.133622 #9374:79be90]  INFO -- : MIQ(EmsOpenstack.with_provider_connection) Connecting through EmsOpenstack: [OpenStack Dev Cloud]
[----] I, [2015-07-27T15:42:49.133845 #9374:79be90]  INFO -- : MIQ(EventCatcherOpenstack) EMS [10.12.12.11] as [anunez] Starting Event Monitor Thread
[----] I, [2015-07-27T15:42:49.133981 #9374:79be90]  INFO -- : MIQ(EventCatcherOpenstack) EMS [10.12.12.11] as [anunez] Started Event Monitor Thread

Any idea of what’s going on?

Thank you,
Alex.


oVirt 3.6.z Refresh failed
#19

@Alex

Seems like this piece of code

In master it’s moved to cloud_manager, but the code is still there, it will throw exception when the security_group description is nil, which is unfortunate, since it’s not mandatory to fill it.

So you can either fill the descriptions of your security groups, or change that line of code to

:description => sg.description.try(:truncate, 255)

I will send a fix to the master


#20

@Alex master fix is here https://github.com/ManageIQ/manageiq/pull/3606