Attachment 716992 Details for Bug 919379 – mcollective.log

mcollective.log

file_919379.txt (text/plain), 19.11 KB, created by Rony Gong 🔥 on 2013-03-27 10:10:46 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Rony Gong 🔥

Created: 2013-03-27 10:10:46 UTC

Size: 19.11 KB

patch

obsolete

>D, [2013-03-27T06:05:02.849614 #1034] DEBUG -- : runnerstats.rb:49:in `received' Incrementing total stat
>D, [2013-03-27T06:05:02.850772 #1034] DEBUG -- : pluginmanager.rb:83:in `[]' Returning cached plugin security_plugin with class MCollective::Security::Psk
>D, [2013-03-27T06:05:02.851161 #1034] DEBUG -- : runnerstats.rb:38:in `validated' Incrementing validated stat
>D, [2013-03-27T06:05:02.852656 #1034] DEBUG -- : pluginmanager.rb:83:in `[]' Returning cached plugin security_plugin with class MCollective::Security::Psk
>D, [2013-03-27T06:05:02.852957 #1034] DEBUG -- : pluginmanager.rb:83:in `[]' Returning cached plugin security_plugin with class MCollective::Security::Psk
>D, [2013-03-27T06:05:02.853338 #1034] DEBUG -- : util.rb:71:in `has_fact?' Comparing active_capacity < 100
>D, [2013-03-27T06:05:02.854428 #1034] DEBUG -- : util.rb:72:in `has_fact?' where :fact = 'active_capacity', :operator = '<', :value = '100'
>D, [2013-03-27T06:05:02.854666 #1034] DEBUG -- : pluginmanager.rb:83:in `[]' Returning cached plugin facts_plugin with class MCollective::Facts::Yaml_facts
>D, [2013-03-27T06:05:02.855175 #1034] DEBUG -- : yaml_facts.rb:51:in `block in force_reload?' Forcing fact reload due to age of /etc/mcollective/facts.yaml
>D, [2013-03-27T06:05:02.855902 #1034] DEBUG -- : base.rb:30:in `block in get_fact' Resetting facter cache, now: 1364378702 last-known-good: 1364378547
>D, [2013-03-27T06:05:02.870401 #1034] DEBUG -- : base.rb:128:in `block (2 levels) in validate_filter?' Passing based on fact active_capacity < 100
>D, [2013-03-27T06:05:02.870630 #1034] DEBUG -- : base.rb:117:in `block (2 levels) in validate_filter?' Passing based on agent rpcutil
>D, [2013-03-27T06:05:02.870832 #1034] DEBUG -- : base.rb:153:in `validate_filter?' Message passed the filter checks
>D, [2013-03-27T06:05:02.871153 #1034] DEBUG -- : runnerstats.rb:26:in `passed' Incrementing passed stat
>D, [2013-03-27T06:05:02.871747 #1034] DEBUG -- : runner.rb:80:in `agentmsg' Handling message for agent 'discovery' on collective 'mcollective'
>D, [2013-03-27T06:05:02.871933 #1034] DEBUG -- : agents.rb:119:in `dispatch' Dispatching a message to agent discovery
>D, [2013-03-27T06:05:02.876124 #1034] DEBUG -- : activemq.rb:233:in `receive' Waiting for a message from ActiveMQ
>D, [2013-03-27T06:05:02.877411 #1034] DEBUG -- : pluginmanager.rb:83:in `[]' Returning cached plugin discovery_agent with class MCollective::Agent::Discovery
>D, [2013-03-27T06:05:02.877760 #1034] DEBUG -- : pluginmanager.rb:83:in `[]' Returning cached plugin security_plugin with class MCollective::Security::Psk
>D, [2013-03-27T06:05:02.877968 #1034] DEBUG -- : pluginmanager.rb:83:in `[]' Returning cached plugin security_plugin with class MCollective::Security::Psk
>D, [2013-03-27T06:05:02.878176 #1034] DEBUG -- : base.rb:168:in `create_reply' Encoded a message for request 36a01b0587a45c6a9758dd7b5a3225b5
>D, [2013-03-27T06:05:02.878627 #1034] DEBUG -- : pluginmanager.rb:83:in `[]' Returning cached plugin connector_plugin with class MCollective::Connector::Activemq
>D, [2013-03-27T06:05:02.878848 #1034] DEBUG -- : activemq.rb:266:in `publish' Sending a broadcast message to ActiveMQ target '/queue/mcollective.reply.ip-10-151-108-218_6186' with headers '{}'
>D, [2013-03-27T06:05:02.886366 #1034] DEBUG -- : runnerstats.rb:56:in `block in sent' Incrementing replies stat
>D, [2013-03-27T06:05:04.680149 #1034] DEBUG -- : runnerstats.rb:49:in `received' Incrementing total stat
>D, [2013-03-27T06:05:04.680340 #1034] DEBUG -- : pluginmanager.rb:83:in `[]' Returning cached plugin security_plugin with class MCollective::Security::Psk
>D, [2013-03-27T06:05:04.680558 #1034] DEBUG -- : runnerstats.rb:38:in `validated' Incrementing validated stat
>D, [2013-03-27T06:05:04.680707 #1034] DEBUG -- : pluginmanager.rb:83:in `[]' Returning cached plugin security_plugin with class MCollective::Security::Psk
>D, [2013-03-27T06:05:04.680893 #1034] DEBUG -- : pluginmanager.rb:83:in `[]' Returning cached plugin security_plugin with class MCollective::Security::Psk
>D, [2013-03-27T06:05:04.681063 #1034] DEBUG -- : util.rb:71:in `has_fact?' Comparing active_capacity < 100
>D, [2013-03-27T06:05:04.681190 #1034] DEBUG -- : util.rb:72:in `has_fact?' where :fact = 'active_capacity', :operator = '<', :value = '100'
>D, [2013-03-27T06:05:04.681356 #1034] DEBUG -- : pluginmanager.rb:83:in `[]' Returning cached plugin facts_plugin with class MCollective::Facts::Yaml_facts
>D, [2013-03-27T06:05:04.681815 #1034] DEBUG -- : yaml_facts.rb:51:in `block in force_reload?' Forcing fact reload due to age of /etc/mcollective/facts.yaml
>D, [2013-03-27T06:05:04.681976 #1034] DEBUG -- : base.rb:30:in `block in get_fact' Resetting facter cache, now: 1364378704 last-known-good: 1364378702
>D, [2013-03-27T06:05:04.687026 #1034] DEBUG -- : base.rb:128:in `block (2 levels) in validate_filter?' Passing based on fact active_capacity < 100
>D, [2013-03-27T06:05:04.687377 #1034] DEBUG -- : base.rb:117:in `block (2 levels) in validate_filter?' Passing based on agent rpcutil
>D, [2013-03-27T06:05:04.687579 #1034] DEBUG -- : base.rb:153:in `validate_filter?' Message passed the filter checks
>D, [2013-03-27T06:05:04.687763 #1034] DEBUG -- : runnerstats.rb:26:in `passed' Incrementing passed stat
>D, [2013-03-27T06:05:04.687953 #1034] DEBUG -- : runner.rb:80:in `agentmsg' Handling message for agent 'rpcutil' on collective 'mcollective'
>D, [2013-03-27T06:05:04.688118 #1034] DEBUG -- : agents.rb:119:in `dispatch' Dispatching a message to agent rpcutil
>D, [2013-03-27T06:05:04.688487 #1034] DEBUG -- : activemq.rb:233:in `receive' Waiting for a message from ActiveMQ
>D, [2013-03-27T06:05:04.688687 #1034] DEBUG -- : pluginmanager.rb:88:in `[]' Returning new plugin rpcutil_agent with class MCollective::Agent::Rpcutil
>D, [2013-03-27T06:05:04.688970 #1034] DEBUG -- : cache.rb:105:in `read' Cache hit on 'ddl' key 'agent/rpcutil'
>D, [2013-03-27T06:05:04.689555 #1034] DEBUG -- : pluginmanager.rb:83:in `[]' Returning cached plugin facts_plugin with class MCollective::Facts::Yaml_facts
>D, [2013-03-27T06:05:04.689796 #1034] DEBUG -- : base.rb:46:in `block in get_fact' Using cached facts now: 1364378704 last-known-good: 1364378704
>D, [2013-03-27T06:05:04.690026 #1034] DEBUG -- : pluginmanager.rb:83:in `[]' Returning cached plugin security_plugin with class MCollective::Security::Psk
>D, [2013-03-27T06:05:04.690335 #1034] DEBUG -- : pluginmanager.rb:83:in `[]' Returning cached plugin security_plugin with class MCollective::Security::Psk
>D, [2013-03-27T06:05:04.690573 #1034] DEBUG -- : base.rb:168:in `create_reply' Encoded a message for request 28ab7e895b695a87b973a6182e7eecc3
>D, [2013-03-27T06:05:04.690899 #1034] DEBUG -- : pluginmanager.rb:83:in `[]' Returning cached plugin connector_plugin with class MCollective::Connector::Activemq
>D, [2013-03-27T06:05:04.691087 #1034] DEBUG -- : activemq.rb:266:in `publish' Sending a broadcast message to ActiveMQ target '/queue/mcollective.reply.ip-10-151-108-218_6186' with headers '{}'
>D, [2013-03-27T06:05:04.694194 #1034] DEBUG -- : runnerstats.rb:56:in `block in sent' Incrementing replies stat
>D, [2013-03-27T06:05:04.821420 #1034] DEBUG -- : runnerstats.rb:49:in `received' Incrementing total stat
>D, [2013-03-27T06:05:04.821589 #1034] DEBUG -- : pluginmanager.rb:83:in `[]' Returning cached plugin security_plugin with class MCollective::Security::Psk
>D, [2013-03-27T06:05:04.821795 #1034] DEBUG -- : runnerstats.rb:38:in `validated' Incrementing validated stat
>D, [2013-03-27T06:05:04.821939 #1034] DEBUG -- : pluginmanager.rb:83:in `[]' Returning cached plugin security_plugin with class MCollective::Security::Psk
>D, [2013-03-27T06:05:04.822114 #1034] DEBUG -- : pluginmanager.rb:83:in `[]' Returning cached plugin security_plugin with class MCollective::Security::Psk
>D, [2013-03-27T06:05:04.822320 #1034] DEBUG -- : base.rb:117:in `block (2 levels) in validate_filter?' Passing based on agent rpcutil
>D, [2013-03-27T06:05:04.822453 #1034] DEBUG -- : base.rb:153:in `validate_filter?' Message passed the filter checks
>D, [2013-03-27T06:05:04.822563 #1034] DEBUG -- : runnerstats.rb:26:in `passed' Incrementing passed stat
>D, [2013-03-27T06:05:04.822668 #1034] DEBUG -- : runner.rb:80:in `agentmsg' Handling message for agent 'rpcutil' on collective 'mcollective'
>D, [2013-03-27T06:05:04.822779 #1034] DEBUG -- : agents.rb:119:in `dispatch' Dispatching a message to agent rpcutil
>D, [2013-03-27T06:05:04.823108 #1034] DEBUG -- : activemq.rb:233:in `receive' Waiting for a message from ActiveMQ
>D, [2013-03-27T06:05:04.823507 #1034] DEBUG -- : pluginmanager.rb:88:in `[]' Returning new plugin rpcutil_agent with class MCollective::Agent::Rpcutil
>D, [2013-03-27T06:05:04.823805 #1034] DEBUG -- : cache.rb:105:in `read' Cache hit on 'ddl' key 'agent/rpcutil'
>D, [2013-03-27T06:05:04.824369 #1034] DEBUG -- : pluginmanager.rb:83:in `[]' Returning cached plugin facts_plugin with class MCollective::Facts::Yaml_facts
>D, [2013-03-27T06:05:04.824623 #1034] DEBUG -- : base.rb:46:in `block in get_fact' Using cached facts now: 1364378704 last-known-good: 1364378704
>D, [2013-03-27T06:05:04.824839 #1034] DEBUG -- : pluginmanager.rb:83:in `[]' Returning cached plugin security_plugin with class MCollective::Security::Psk
>D, [2013-03-27T06:05:04.825038 #1034] DEBUG -- : pluginmanager.rb:83:in `[]' Returning cached plugin security_plugin with class MCollective::Security::Psk
>D, [2013-03-27T06:05:04.825359 #1034] DEBUG -- : base.rb:168:in `create_reply' Encoded a message for request a8e278ba32c15de7aaf4d150130e5e6e
>D, [2013-03-27T06:05:04.825689 #1034] DEBUG -- : pluginmanager.rb:83:in `[]' Returning cached plugin connector_plugin with class MCollective::Connector::Activemq
>D, [2013-03-27T06:05:04.825887 #1034] DEBUG -- : activemq.rb:266:in `publish' Sending a broadcast message to ActiveMQ target '/queue/mcollective.reply.ip-10-151-108-218_6186' with headers '{}'
>D, [2013-03-27T06:05:04.835513 #1034] DEBUG -- : runnerstats.rb:56:in `block in sent' Incrementing replies stat
>D, [2013-03-27T06:05:04.917451 #1034] DEBUG -- : runnerstats.rb:49:in `received' Incrementing total stat
>D, [2013-03-27T06:05:04.917608 #1034] DEBUG -- : pluginmanager.rb:83:in `[]' Returning cached plugin security_plugin with class MCollective::Security::Psk
>D, [2013-03-27T06:05:04.917798 #1034] DEBUG -- : runnerstats.rb:38:in `validated' Incrementing validated stat
>D, [2013-03-27T06:05:04.917970 #1034] DEBUG -- : pluginmanager.rb:83:in `[]' Returning cached plugin security_plugin with class MCollective::Security::Psk
>D, [2013-03-27T06:05:04.918149 #1034] DEBUG -- : pluginmanager.rb:83:in `[]' Returning cached plugin security_plugin with class MCollective::Security::Psk
>D, [2013-03-27T06:05:04.918356 #1034] DEBUG -- : base.rb:117:in `block (2 levels) in validate_filter?' Passing based on agent openshift
>D, [2013-03-27T06:05:04.918488 #1034] DEBUG -- : base.rb:153:in `validate_filter?' Message passed the filter checks
>D, [2013-03-27T06:05:04.918603 #1034] DEBUG -- : runnerstats.rb:26:in `passed' Incrementing passed stat
>D, [2013-03-27T06:05:04.918708 #1034] DEBUG -- : runner.rb:80:in `agentmsg' Handling message for agent 'openshift' on collective 'mcollective'
>D, [2013-03-27T06:05:04.918823 #1034] DEBUG -- : agents.rb:119:in `dispatch' Dispatching a message to agent openshift
>D, [2013-03-27T06:05:04.919109 #1034] DEBUG -- : activemq.rb:233:in `receive' Waiting for a message from ActiveMQ
>D, [2013-03-27T06:05:04.919557 #1034] DEBUG -- : pluginmanager.rb:88:in `[]' Returning new plugin openshift_agent with class MCollective::Agent::Openshift
>D, [2013-03-27T06:05:04.919881 #1034] DEBUG -- : cache.rb:105:in `read' Cache hit on 'ddl' key 'agent/openshift'
>I, [2013-03-27T06:05:04.922183 #1034]  INFO -- : openshift.rb:42:in `cartridge_do_action' cartridge_do_action call / action: cartridge_do, agent=openshift, data={:cartridge=>"openshift-origin-node",
> :action=>"app-create",
> :args=>
>  {"--with-app-uuid"=>"5152c3b36965130978000001",
>   "--with-app-name"=>"qperl",
>   "--with-container-uuid"=>"5152c3b36965130978000001",
>   "--with-container-name"=>"qperl",
>   "--with-namespace"=>"qgong1",
>   "--with-request-id"=>nil,
>   "--cart-name"=>"openshift-origin-node"},
> :process_results=>true}
>
>I, [2013-03-27T06:05:04.922489 #1034]  INFO -- : openshift.rb:43:in `cartridge_do_action' cartridge_do_action validation = openshift-origin-node app-create {"--with-app-uuid"=>"5152c3b36965130978000001", "--with-app-name"=>"qperl", "--with-container-uuid"=>"5152c3b36965130978000001", "--with-container-name"=>"qperl", "--with-namespace"=>"qgong1", "--with-request-id"=>nil, "--cart-name"=>"openshift-origin-node"}
>I, [2013-03-27T06:05:04.922975 #1034]  INFO -- : openshift.rb:82:in `execute_action' Executing action [app-create] using method oo_app_create with args [{"--with-app-uuid"=>"5152c3b36965130978000001", "--with-app-name"=>"qperl", "--with-container-uuid"=>"5152c3b36965130978000001", "--with-container-name"=>"qperl", "--with-namespace"=>"qgong1", "--with-request-id"=>nil, "--cart-name"=>"openshift-origin-node"}]
>I, [2013-03-27T06:05:04.982762 #1034]  INFO -- : openshift.rb:157:in `rescue in oo_app_create' ERROR: unable to create user account(9): useradd -u 501 -d /var/lib/openshift/5152c3b36965130978000001/ -s /usr/bin/oo-trap-user -c 'OpenShift guest' -m -k /etc/openshift/skel 5152c3b36965130978000001 stdout: useradd: user '5152c3b36965130978000001' already exists
> stderr: useradd: user '5152c3b36965130978000001' already exists
>
>I, [2013-03-27T06:05:04.983132 #1034]  INFO -- : openshift.rb:158:in `rescue in oo_app_create' ["/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-node-1.6.8/lib/openshift-origin-node/model/unix_user.rb:130:in `block (2 levels) in create'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-node-1.6.8/lib/openshift-origin-node/model/unix_user.rb:108:in `open'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-node-1.6.8/lib/openshift-origin-node/model/unix_user.rb:108:in `block in create'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-node-1.6.8/lib/openshift-origin-node/model/unix_user.rb:101:in `open'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-node-1.6.8/lib/openshift-origin-node/model/unix_user.rb:101:in `create'", "/opt/rh/ruby193/root/usr/share/gems/gems/openshift-origin-node-1.6.8/lib/openshift-origin-node/model/application_container.rb:111:in `create'", "/opt/rh/ruby193/root/usr/libexec/mcollective/mcollective/agent/openshift.rb:155:in `oo_app_create'", "/opt/rh/ruby193/root/usr/libexec/mcollective/mcollective/agent/openshift.rb:84:in `execute_action'", "/opt/rh/ruby193/root/usr/libexec/mcollective/mcollective/agent/openshift.rb:56:in `cartridge_do_action'", "/opt/rh/ruby193/root/usr/share/ruby/mcollective/rpc/agent.rb:86:in `handlemsg'", "/opt/rh/ruby193/root/usr/share/ruby/mcollective/agents.rb:126:in `block (2 levels) in dispatch'", "/opt/rh/ruby193/root/usr/share/ruby/timeout.rb:68:in `timeout'", "/opt/rh/ruby193/root/usr/share/ruby/mcollective/agents.rb:125:in `block in dispatch'"]
>I, [2013-03-27T06:05:04.983325 #1034]  INFO -- : openshift.rb:91:in `execute_action' Finished executing action [app-create] (129)
>I, [2013-03-27T06:05:04.983525 #1034]  INFO -- : openshift.rb:64:in `cartridge_do_action' cartridge_do_action failed (129)
>------
>ERROR: unable to create user account(9): useradd -u 501 -d /var/lib/openshift/5152c3b36965130978000001/ -s /usr/bin/oo-trap-user -c 'OpenShift guest' -m -k /etc/openshift/skel 5152c3b36965130978000001 stdout: useradd: user '5152c3b36965130978000001' already exists
> stderr: useradd: user '5152c3b36965130978000001' already exists
>
>------)
>D, [2013-03-27T06:05:04.983827 #1034] DEBUG -- : pluginmanager.rb:83:in `[]' Returning cached plugin security_plugin with class MCollective::Security::Psk
>D, [2013-03-27T06:05:04.983980 #1034] DEBUG -- : pluginmanager.rb:83:in `[]' Returning cached plugin security_plugin with class MCollective::Security::Psk
>D, [2013-03-27T06:05:04.984191 #1034] DEBUG -- : base.rb:168:in `create_reply' Encoded a message for request 33bed80d7a8558c58ab6d8a95b9b4a41
>D, [2013-03-27T06:05:04.984628 #1034] DEBUG -- : pluginmanager.rb:83:in `[]' Returning cached plugin connector_plugin with class MCollective::Connector::Activemq
>D, [2013-03-27T06:05:04.984848 #1034] DEBUG -- : activemq.rb:266:in `publish' Sending a broadcast message to ActiveMQ target '/queue/mcollective.reply.ip-10-151-108-218_6186' with headers '{}'
>D, [2013-03-27T06:05:04.989130 #1034] DEBUG -- : runnerstats.rb:56:in `block in sent' Incrementing replies stat
>D, [2013-03-27T06:05:05.100476 #1034] DEBUG -- : runnerstats.rb:49:in `received' Incrementing total stat
>D, [2013-03-27T06:05:05.100651 #1034] DEBUG -- : pluginmanager.rb:83:in `[]' Returning cached plugin security_plugin with class MCollective::Security::Psk
>D, [2013-03-27T06:05:05.100847 #1034] DEBUG -- : runnerstats.rb:38:in `validated' Incrementing validated stat
>D, [2013-03-27T06:05:05.100996 #1034] DEBUG -- : pluginmanager.rb:83:in `[]' Returning cached plugin security_plugin with class MCollective::Security::Psk
>D, [2013-03-27T06:05:05.101184 #1034] DEBUG -- : pluginmanager.rb:83:in `[]' Returning cached plugin security_plugin with class MCollective::Security::Psk
>D, [2013-03-27T06:05:05.101460 #1034] DEBUG -- : base.rb:117:in `block (2 levels) in validate_filter?' Passing based on agent rpcutil
>D, [2013-03-27T06:05:05.101603 #1034] DEBUG -- : base.rb:153:in `validate_filter?' Message passed the filter checks
>D, [2013-03-27T06:05:05.101722 #1034] DEBUG -- : runnerstats.rb:26:in `passed' Incrementing passed stat
>D, [2013-03-27T06:05:05.101834 #1034] DEBUG -- : runner.rb:80:in `agentmsg' Handling message for agent 'rpcutil' on collective 'mcollective'
>D, [2013-03-27T06:05:05.101950 #1034] DEBUG -- : agents.rb:119:in `dispatch' Dispatching a message to agent rpcutil
>D, [2013-03-27T06:05:05.102429 #1034] DEBUG -- : activemq.rb:233:in `receive' Waiting for a message from ActiveMQ
>D, [2013-03-27T06:05:05.102697 #1034] DEBUG -- : pluginmanager.rb:88:in `[]' Returning new plugin rpcutil_agent with class MCollective::Agent::Rpcutil
>D, [2013-03-27T06:05:05.103097 #1034] DEBUG -- : cache.rb:105:in `read' Cache hit on 'ddl' key 'agent/rpcutil'
>D, [2013-03-27T06:05:05.103806 #1034] DEBUG -- : pluginmanager.rb:83:in `[]' Returning cached plugin facts_plugin with class MCollective::Facts::Yaml_facts
>D, [2013-03-27T06:05:05.104071 #1034] DEBUG -- : base.rb:46:in `block in get_fact' Using cached facts now: 1364378705 last-known-good: 1364378704
>D, [2013-03-27T06:05:05.104419 #1034] DEBUG -- : pluginmanager.rb:83:in `[]' Returning cached plugin security_plugin with class MCollective::Security::Psk
>D, [2013-03-27T06:05:05.104619 #1034] DEBUG -- : pluginmanager.rb:83:in `[]' Returning cached plugin security_plugin with class MCollective::Security::Psk
>D, [2013-03-27T06:05:05.104824 #1034] DEBUG -- : base.rb:168:in `create_reply' Encoded a message for request a397885e15185d55a183f0cea6d2007d
>D, [2013-03-27T06:05:05.105179 #1034] DEBUG -- : pluginmanager.rb:83:in `[]' Returning cached plugin connector_plugin with class MCollective::Connector::Activemq
>D, [2013-03-27T06:05:05.105562 #1034] DEBUG -- : activemq.rb:266:in `publish' Sending a broadcast message to ActiveMQ target '/queue/mcollective.reply.ip-10-151-108-218_6186' with headers '{}'
>D, [2013-03-27T06:05:05.108602 #1034] DEBUG -- : runnerstats.rb:56:in `block in sent' Incrementing replies stat

Actions: View

Attachments on bug 919379: 716989 | 716990 | 716992