Bug 725356

Summary: Not able to register CDS nodes on amazon
Product: Red Hat Update Infrastructure for Cloud Providers Reporter: Kedar Bidarkar <kbidarka>
Component: ToolsAssignee: Jeff Ortel <jortel>
Status: CLOSED NOTABUG QA Contact: wes hayutin <whayutin>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 2.0CC: kbidarka, sghai, tsanders
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2011-07-25 15:00:54 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:

Description Kedar Bidarkar 2011-07-25 09:57:28 UTC
Description of problem:


Earlier had faced this issue for the amazon nodes, but using the `hostname` had solved this issue. 

Strangely now we are not able to register the CDS nodes while building a setup at amazon, even after using the CDS hostnames as `hostname`.

/var/log/gofer/agent.log on CDS node being registered.
2011-07-25 05:17:11,112 [INFO][MainThread] __init__() @ config.py:372 - reading: /etc/gofer/agent.conf
2011-07-25 05:17:11,119 [INFO][MainThread] __init__() @ config.py:372 - reading: /etc/gofer/plugins/builtin.conf
2011-07-25 05:17:11,121 [INFO][MainThread] __init__() @ config.py:372 - reading: /etc/gofer/plugins/cdsplugin.conf
2011-07-25 05:17:11,121 [INFO][MainThread] __import() @ config.py:420 - processing: @import:/etc/pulp/cds.conf:server:host(host)
2011-07-25 05:17:11,121 [INFO][MainThread] __init__() @ config.py:372 - reading: /etc/pulp/cds.conf
2011-07-25 05:17:11,123 [INFO][MainThread] __import() @ config.py:420 - processing: @import:/etc/pulp/cds.conf:messaging:scheme(scheme),port(port),cacert(cacert),clientcert(clientcert)
2011-07-25 05:17:11,123 [INFO][MainThread] __init__() @ config.py:372 - reading: /etc/pulp/cds.conf
2011-07-25 05:17:11,125 [INFO][MainThread] __import() @ config.py:420 - processing: @import:/etc/pulp/cds.conf:server
2011-07-25 05:17:11,125 [INFO][MainThread] __init__() @ config.py:372 - reading: /etc/pulp/cds.conf
2011-07-25 05:17:11,127 [INFO][MainThread] __import() @ config.py:420 - processing: @import:/etc/pulp/cds.conf:cds
2011-07-25 05:17:11,127 [INFO][MainThread] __init__() @ config.py:372 - reading: /etc/pulp/cds.conf
2011-07-25 05:17:11,129 [INFO][MainThread] __import() @ config.py:420 - processing: @import:/etc/pulp/cds.conf:heartbeat
2011-07-25 05:17:11,129 [INFO][MainThread] __init__() @ config.py:372 - reading: /etc/pulp/cds.conf
2011-07-25 05:17:11,131 [INFO][MainThread] __repl() @ config.py:440 - line "uuid = cds-%{hostname}" s/%{hostname}/ip-10-124-43-201/
2011-07-25 05:17:11,131 [INFO][MainThread] __repl() @ config.py:440 - line "url = $(scheme)://$(host):$(port)" s/$(host)/ip-10-91-18-210.ec2.internal/
2011-07-25 05:17:11,131 [INFO][MainThread] __repl() @ config.py:440 - line "url = $(scheme)://ip-10-91-18-210.ec2.internal:$(port)" s/$(port)/5674/
2011-07-25 05:17:11,132 [INFO][MainThread] __repl() @ config.py:440 - line "url = $(scheme)://ip-10-91-18-210.ec2.internal:5674" s/$(scheme)/ssl/
2011-07-25 05:17:11,132 [INFO][MainThread] __repl() @ config.py:440 - line "cacert = $(cacert)" s/$(cacert)//etc/pki/cds/qpid-ca.crt/
2011-07-25 05:17:11,132 [INFO][MainThread] __repl() @ config.py:440 - line "clientcert = $(clientcert)" s/$(clientcert)//etc/pki/cds/qpid-client.crt/
2011-07-25 05:17:11,132 [INFO][MainThread] __import() @ config.py:420 - processing: @import:/etc/pulp/repo_auth.conf:repos
2011-07-25 05:17:11,132 [INFO][MainThread] __init__() @ config.py:372 - reading: /etc/pulp/repo_auth.conf
2011-07-25 05:17:11,137 [INFO][MainThread] __import() @ plugin.py:363 - plugin "builtin", imported as: "builtin"
2011-07-25 05:17:11,262 [INFO][MainThread] __import() @ plugin.py:363 - plugin "cdsplugin", imported as: "cdsplugin"
2011-07-25 05:17:11,272 [INFO][Actions] hello() @ builtin.py:39 - Hello:
[main]
enabled=1

[messaging]
url=
uuid=admin@ip-10-124-43-201


2011-07-25 05:17:11,272 [INFO][MainThread] __init__() @ main.py:130 - agent started.
2011-07-25 05:17:11,273 [INFO][cdsplugin-monitor] getbroker() @ plugin.py:185 - broker (qpid) configured: {ip-10-91-18-210.ec2.internal:5674}:
transport=SSL
host=ip-10-91-18-210.ec2.internal
port=5674
cacert=/etc/pki/cds/qpid-ca.crt
clientcert=/etc/pki/cds/qpid-client.crt
2011-07-25 05:17:11,342 [INFO][pending:cds-ip-10-124-43-201] run() @ store.py:235 - started
2011-07-25 05:17:11,343 [INFO][cdsplugin-monitor] update() @ main.py:101 - uuid="cds-ip-10-124-43-201", attached
2011-07-25 05:17:11,343 [INFO][cds-ip-10-124-43-201] connect() @ broker.py:100 - connecting:
{ip-10-91-18-210.ec2.internal:5674}:
transport=SSL
host=ip-10-91-18-210.ec2.internal
port=5674
cacert=/etc/pki/cds/qpid-ca.crt
clientcert=/etc/pki/cds/qpid-client.crt
2011-07-25 05:17:32,395 [WARNING][cds-ip-10-124-43-201] close_engine() @ driver.py:444 - recoverable error[attempt 1]: [Errno 110] Connection timed out
2011-07-25 05:17:32,395 [WARNING][cds-ip-10-124-43-201] close_engine() @ driver.py:446 - sleeping 1 seconds
2011-07-25 05:17:33,396 [WARNING][Thread-1] connect() @ driver.py:523 - trying: ip-10-91-18-210.ec2.internal:5674
2011-07-25 05:17:54,397 [WARNING][Thread-1] close_engine() @ driver.py:444 - recoverable error[attempt 2]: [Errno 110] Connection timed out
2011-07-25 05:17:54,397 [WARNING][Thread-1] close_engine() @ driver.py:446 - sleeping 2 seconds
2011-07-25 05:17:56,399 [WARNING][Thread-1] connect() @ driver.py:523 - trying: ip-10-91-18-210.ec2.internal:5674
2011-07-25 05:18:17,400 [WARNING][Thread-1] close_engine() @ driver.py:444 - recoverable error[attempt 3]: [Errno 110] Connection timed out
2011-07-25 05:18:17,401 [WARNING][Thread-1] close_engine() @ driver.py:446 - sleeping 4 seconds
2011-07-25 05:18:21,404 [WARNING][Thread-1] connect() @ driver.py:523 - trying: ip-10-91-18-210.ec2.internal:5674
2011-07-25 05:18:42,405 [WARNING][Thread-1] close_engine() @ driver.py:444 - recoverable error[attempt 4]: [Errno 110] Connection timed out
2011-07-25 05:18:42,405 [WARNING][Thread-1] close_engine() @ driver.py:446 - sleeping 8 seconds
2011-07-25 05:18:50,413 [WARNING][Thread-1] connect() @ driver.py:523 - trying: ip-10-91-18-210.ec2.internal:5674
2011-07-25 05:19:11,414 [WARNING][Thread-1] close_engine() @ driver.py:444 - recoverable error[attempt 5]: [Errno 110] Connection timed out
2011-07-25 05:19:11,414 [WARNING][Thread-1] close_engine() @ driver.py:446 - sleeping 16 seconds

/var/log/pulp/pulp.log
2011-07-25 05:17:04,130 2368:140511126161376: pulp.server.async:INFO: async:333 Task reply handler, started.
2011-07-25 05:17:04,131 2368:140510759155472: gofer.messaging.broker:INFO: broker:100 connecting:
{ip-10-91-18-210.ec2.internal:5674}:
transport=SSL
host=ip-10-91-18-210.ec2.internal
port=5674
cacert=/etc/pki/rhua/qpid-ca.crt
clientcert=/etc/pki/rhua/qpid-client.crt
2011-07-25 05:17:04,158 2368:140510759155472: gofer.messaging.broker:INFO: broker:103 {ip-10-91-18-210.ec2.internal:5674} connected to AMQP
2011-07-25 05:17:53,751 2368:140510618433296: pulp.server.db.connection:INFO: connection:46 Attempting Database connection with seeds = ip-10-91-18-210.ec2.internal
2011-07-25 05:17:53,755 2368:140510618433296: pulp.server.db.connection:INFO: connection:51 Database connection established with: seeds = ip-10-91-18-210.ec2.internal, name = pulp_database
2011-07-25 05:18:30,102 2368:140510618433296: gofer.messaging.policy:INFO: policy:116 sent (cds-ip-10-124-43-201):
{
  "classname": "cdsplugin",
  "kws": {},
  "args": [],
  "method": "initialize"
}
2011-07-25 05:18:40,123 2368:140510618433296: pulp.server.webservices.controllers.decorators:ERROR: decorators:50 Traceback (most recent call last):
  File "/usr/lib/python2.6/site-packages/pulp/server/webservices/controllers/decorators.py", line 46, in report_error
    return method(self, *args, **kwargs)
  File "/usr/lib/python2.6/site-packages/pulp/server/webservices/controllers/decorators.py", line 125, in _auth_decorator
    value = method(self, *args, **kwargs)
  File "/usr/lib/python2.6/site-packages/pulp/server/webservices/controllers/cds.py", line 76, in POST
    cds = cds_api.register(hostname, name, description, sync_schedule=sync_schedule, cluster_id=cluster_id)
  File "/usr/lib/python2.6/site-packages/pulp/server/api/cds.py", line 120, in register
    secret = self.dispatcher.init_cds(cds)
  File "/usr/lib/python2.6/site-packages/pulp/server/cds/dispatcher.py", line 93, in init_cds
    secret = self._send(self._cds_stub(cds).initialize)
  File "/usr/lib/python2.6/site-packages/pulp/server/cds/dispatcher.py", line 170, in _send
    result = func(*args)
  File "/usr/lib/python2.6/site-packages/gofer/messaging/stub.py", line 71, in __call__
    return self.stub._send(request, opts)
  File "/usr/lib/python2.6/site-packages/gofer/messaging/stub.py", line 142, in _send
    any=opts.any)
  File "/usr/lib/python2.6/site-packages/gofer/messaging/policy.py", line 120, in send
    self.__getstarted(sn, reader)
  File "/usr/lib/python2.6/site-packages/gofer/messaging/policy.py", line 158, in __getstarted
    raise RequestTimeout(sn)
PulpException: 'Timeout occurred attempting to initialize CDS [ip-10-124-43-201]'



Version-Release number of selected component (if applicable):
pulp - 211 and rhui - 2.0.40 

How reproducible:
Trying to register a CDS node on amazon.

Steps to Reproduce:
1. register CDS hostname.
2.
3.
  
Actual results:
CDS register fails

Expected results:
CDS nodes should get registered

Additional info:

Comment 1 Jay Dobies 2011-07-25 12:14:35 UTC
Jeff - Please work with Kedar to see if this is an environment issue or something bigger in EC2.

Comment 2 Jeff Ortel 2011-07-25 13:38:00 UTC
Based on the log, the CDS can't connect to the qpid broker on ip-10-91-18-210.ec2.internal.

Comment 3 Kedar Bidarkar 2011-07-25 15:00:54 UTC
qpid port 5674 was blocked at amazon , other port was opened due to typo.