Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.

Bug 618781

Summary: pulp package install failing
Product: [Retired] Pulp Reporter: Preethi Thomas <pthomas>
Component: z_otherAssignee: Pradeep Kilambi <pkilambi>
Status: CLOSED CURRENTRELEASE QA Contact: Preethi Thomas <pthomas>
Severity: medium Docs Contact:
Priority: low    
Version: unspecifiedCC: ssachdev, whayutin
Target Milestone: ---   
Target Release: ---   
Hardware: All   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2011-08-16 13:59:05 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On: 629360    
Bug Blocks: 647488    

Description Preethi Thomas 2010-07-27 17:50:55 UTC 
Description of problem:

pulp package install command is not installing packages

error in /var/log/pulp/pulptools.log


[root@preethi ~]#  pulp consumer bind --repoid=f13 --id=preethi.usersys.redhat.com
 Successfully subscribed Consumer [preethi.usersys.redhat.com] to Repo [f13]


[root@preethi ~]# pulp package install -p /var/lib/pulp/f13/Packages/zsh-4.3.10-5.fc13.x86_64.rpm --consumerid=preethi.usersys.redhat.com


2010-07-27 13:22:15,783 [INFO][MainThread] setUp() @ connection.py:118 - Connection Established for cli: Host: localhost, Port: 8811, handler: 
2010-07-27 13:22:15,784 [INFO][MainThread] setUp() @ connection.py:119 - Using cert_file: None and key_file: None
2010-07-27 13:22:15,784 [INFO][MainThread] setUp() @ connection.py:118 - Connection Established for cli: Host: localhost, Port: 8811, handler: 
2010-07-27 13:22:15,784 [INFO][MainThread] setUp() @ connection.py:119 - Using cert_file: None and key_file: None
2010-07-27 13:22:35,305 [INFO][MainThread] setUp() @ connection.py:118 - Connection Established for cli: Host: localhost, Port: 8811, handler: 
2010-07-27 13:22:35,305 [INFO][MainThread] setUp() @ connection.py:119 - Using cert_file: None and key_file: None
2010-07-27 13:22:49,085 [INFO][MainThread] setUp() @ connection.py:118 - Connection Established for cli: Host: localhost, Port: 8811, handler: 
2010-07-27 13:22:49,086 [INFO][MainThread] setUp() @ connection.py:119 - Using cert_file: None and key_file: None
2010-07-27 13:24:06,105 [INFO][Actions] __call__() @ action.py:82 - perform "TestAction"
2010-07-27 13:24:06,105 [INFO][Actions] perform() @ actions.py:36 - Hello
2010-07-27 13:24:11,181 [WARNING][Thread-1] connect() @ driver.py:492 - trying: localhost:5672
2010-07-27 13:24:11,181 [WARNING][Thread-1] close_engine() @ driver.py:432 - recoverable error[attempt 102]: [Errno 111] Connection refused
Comment 1 Preethi Thomas 2010-07-27 17:52:01 UTC 
[root@preethi ~]# pulp consumer list
+-------------------------------------------+
    Consumer Information 
+-------------------------------------------+

Id                      preethi.usersys.redhat.com
Description             preethi.usersys.redhat.com
Subscribed Repos        /consumers/preethi.usersys.redhat.com/repoids/
Profile                 http://localhost:8811/consumers/preethi.usersys.redhat.com/package_profile/
Comment 2 Preethi Thomas 2010-07-29 18:34:22 UTC 
[root@preethi ~]# pulp consumer create --id=preethi --server=preethi.usersys.redhat.com

[root@preethi ~]# pulp consumer bind --repoid=f13 --id=preethi
 Successfully subscribed Consumer [preethi] to Repo [f13]
[root@preethi ~]# pulp package install --help
Usage: pulp package install [OPTIONS]

Options:
  -h, --help            show this help message and exit
  -p PNAMES, --name=PNAMES
                        Packages to be installed.
                        To specify multiple packages use multiple -p
  --consumerid=CONSUMERID
                        Consumer Id
  --consumergroupid=CONSUMERGROUPID
                        Consumer Group Id

[root@preethi ~]# pulp package install --consumerid=preethi -p zsh


[root@preethi ~]# tail -f /var/log/pulp/pulptools.log
2010-07-29 14:32:24,057 [WARNING][Thread-1] close_engine() @ driver.py:434 - sleeping 120 seconds
2010-07-29 14:34:24,086 [WARNING][Thread-1] connect() @ driver.py:492 - trying: localhost:5672
2010-07-29 14:34:24,087 [WARNING][Thread-1] close_engine() @ driver.py:432 - recoverable error[attempt 789]: [Errno 111] Connection refused
Comment 4 Shveta 2010-08-20 09:27:31 UTC 
[root@shveta conf.d]# pulp-admin -u admin -p admin package install --name=zsh-4.2.6-3.el5.x86_64.rpm --consumerid=10.65.193.75
<!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">
<html><head>
<title>500 Internal Server Error</title>
</head><body>
<h1>Internal Server Error</h1>
<p>The server encountered an internal error or
misconfiguration and was unable to complete
your request.</p>
<p>Please contact the server administrator,
 root@localhost and inform them of the time the error occurred,
and anything you might have done that may have
caused the error.</p>
<p>More information about this error may be available
in the server error log.</p>
<hr>
<address>Apache/2.2.15 (Fedora) Server at localhost Port 8811</address>
</body></html>
Comment 7 Preethi Thomas 2010-08-23 21:08:03 UTC 
verified
[root@preethi yum.repos.d]# rpm -qa |grep zsh
[root@preethi yum.repos.d]# 
[root@preethi yum.repos.d]# pulp-admin -u admin -p admin package install -n zsh --consumerid=preethi.usersys.redhat.com
[u'zsh']
root@preethi yum.repos.d]# rpm -qa |grep zsh
zsh-4.3.10-5.fc13.x86_64
Comment 8 Preethi Thomas 2010-08-26 20:48:33 UTC 
failing now with
0.57

[root@preethi ~]# pulp-admin -u admin -p admin package install -n zsh --consumerid=preethi.usersys.redhat.com
"Traceback (most recent call last):\n  File \"/usr/lib/python2.6/site-packages/pulp/server/webservices/controllers/base.py\", line 51, in report_error\n    return method(self, *args, **kwargs)\n  File \"/usr/lib/python2.6/site-packages/pulp/server/webservices/controllers/consumers.py\", line 310, in POST\n    return action(id)\n  File \"/usr/lib/python2.6/site-packages/pulp/server/webservices/role_check.py\", line 102, in check_roles\n    result = f(instance, *fargs, **kw)\n  File \"/usr/lib/python2.6/site-packages/pulp/server/webservices/controllers/consumers.py\", line 262, in installpackages\n    return self.ok(api.installpackages(id, names))\n  File \"/usr/lib/python2.6/site-packages/pulp/server/auditing.py\", line 186, in _audit\n    result = method(*args, **kwargs)\n  File \"/usr/lib/python2.6/site-packages/pulp/server/api/consumer.py\", line 204, in installpackages\n    agent.packages.install(data)\n  File \"/usr/lib/python2.6/site-packages/pulp/messaging/stub.py\", line 69, in __call__\n    return self.stub._send(request, opts)\n  File \"/usr/lib/python2.6/site-packages/pulp/messaging/stub.py\", line 111, in _send\n    any=opts.any)\n  File \"/usr/lib/python2.6/site-packages/pulp/messaging/policy.py\", line 120, in send\n    self.__getstarted(sn)\n  File \"/usr/lib/python2.6/site-packages/pulp/messaging/policy.py\", line 128, in __getstarted\n    raise RequestTimeout(sn)\nRequestTimeout: b8168331-73f8-4526-b0de-eac0f6d784cd\n"
Comment 9 Pradeep Kilambi 2010-08-26 20:51:40 UTC 
commit da0cd477e289072401e2d3081925fc984a5516de
Author: Pradeep Kilambi <pkilambi>
Date:   Thu Aug 26 16:43:14 2010 -0400

# pulp-admin -u admin -p admin package install -n zsh --consumerid=preethi.usersys.redhat.com
[u'zsh']


2010-08-26 16:57:10,361 [INFO][preethi.usersys.redhat.com] dispatch() @ dispatcher.py:214 - dispatching:{
  "classname": "Packages", 
  "kws": {}, 
  "args": [
    [
      "zsh"
    ]
  ], 
  "method": "install"
}
2010-08-26 16:57:10,361 [INFO][preethi.usersys.redhat.com] install() @ remote.py:62 - installing packages: ['zsh']
2010-08-26 16:57:18,218 [INFO][preethi.usersys.redhat.com] send() @ producer.py:56 - {db348a7a-c1dc-4a2f-abdc-cc0342800b4d} sent (b1152452-c9f4-42fc-8af0-f0c3c8b9f2ea;{create:always,delete:receiver,node:{type:queue},link:{durable:True}})
{
  "origin": "db348a7a-c1dc-4a2f-abdc-cc0342800b4d", 
  "version": "0.1", 
  "sn": "84e33d18-282f-4539-83dc-a19453026b74", 
  "any": null, 
  "result": {
    "retval": null
  }
}
Comment 10 Preethi Thomas 2010-08-30 18:10:22 UTC 
fails_qa

[root@preethi ~]# rpm -qa |grep pulp
pulp-0.0.58-1.fc13.noarch
pulp-common-0.0.58-1.fc13.noarch
pulp-client-0.0.58-1.fc13.noarch


[root@preethi ~]# pulp-admin package install -n zsh --consumerid=preethi.usersys.redhat.com
"Traceback (most recent call last):\n  File \"/usr/lib/python2.6/site-packages/pulp/server/webservices/controllers/base.py\", line 51, in report_error\n    return method(self, *args, **kwargs)\n  File \"/usr/lib/python2.6/site-packages/pulp/server/webservices/controllers/consumers.py\", line 310, in POST\n    return action(id)\n  File \"/usr/lib/python2.6/site-packages/pulp/server/webservices/role_check.py\", line 106, in check_roles\n    result = f(instance, *fargs, **kw)\n  File \"/usr/lib/python2.6/site-packages/pulp/server/webservices/controllers/consumers.py\", line 262, in installpackages\n    return self.ok(api.installpackages(id, names))\n  File \"/usr/lib/python2.6/site-packages/pulp/server/auditing.py\", line 186, in _audit\n    result = method(*args, **kwargs)\n  File \"/usr/lib/python2.6/site-packages/pulp/server/api/consumer.py\", line 204, in installpackages\n    agent.packages.install(data)\n  File \"/usr/lib/python2.6/site-packages/pulp/messaging/stub.py\", line 69, in __call__\n    return self.stub._send(request, opts)\n  File \"/usr/lib/python2.6/site-packages/pulp/messaging/stub.py\", line 111, in _send\n    any=opts.any)\n  File \"/usr/lib/python2.6/site-packages/pulp/messaging/policy.py\", line 120, in send\n    self.__getstarted(sn)\n  File \"/usr/lib/python2.6/site-packages/pulp/messaging/policy.py\", line 128, in __getstarted\n    raise RequestTimeout(sn)\nRequestTimeout: 42bb4b72-3a8b-47b3-b6df-a63edd17894b\n"
[root@preethi ~]# 


2010-08-30 14:16:24,696  {eac53600-c61d-4912-93a7-3799795eb139} connected to AMQP
2010-08-30 14:16:24,697  {eac53600-c61d-4912-93a7-3799795eb139} opening eac53600-c61d-4912-93a7-3799795eb139;{create:always,delete:receiver,node:{type:queue},link:{durable:True}}
2010-08-30 14:16:24,703  {f24a23c4-7991-4ddf-af6b-ca264d06ec5c} connected to AMQP
2010-08-30 14:16:24,709  {f24a23c4-7991-4ddf-af6b-ca264d06ec5c} sent (preethi.usersys.redhat.com;{create:always,node:{type:queue,durable:True},link:{durable:True}})
{
  "origin": "f24a23c4-7991-4ddf-af6b-ca264d06ec5c", 
  "window": {}, 
  "version": "0.1", 
  "sn": "42bb4b72-3a8b-47b3-b6df-a63edd17894b", 
  "replyto": "eac53600-c61d-4912-93a7-3799795eb139;{create:always,delete:receiver,node:{type:queue},link:{durable:True}}", 
  "request": {
    "classname": "Packages", 
    "kws": {}, 
    "args": [
      [
        "zsh"
      ]
    ], 
    "method": "install"
  }, 
  "any": null
}
2010-08-30 14:16:24,709  {eac53600-c61d-4912-93a7-3799795eb139} searching for: sn=42bb4b72-3a8b-47b3-b6df-a63edd17894b
2010-08-30 14:17:54,804  Traceback (most recent call last):
  File "/usr/lib/python2.6/site-packages/pulp/server/webservices/controllers/base.py", line 51, in report_error
    return method(self, *args, **kwargs)
  File "/usr/lib/python2.6/site-packages/pulp/server/webservices/controllers/consumers.py", line 310, in POST
    return action(id)
  File "/usr/lib/python2.6/site-packages/pulp/server/webservices/role_check.py", line 106, in check_roles
    result = f(instance, *fargs, **kw)
  File "/usr/lib/python2.6/site-packages/pulp/server/webservices/controllers/consumers.py", line 262, in installpackages
    return self.ok(api.installpackages(id, names))
  File "/usr/lib/python2.6/site-packages/pulp/server/auditing.py", line 186, in _audit
    result = method(*args, **kwargs)
  File "/usr/lib/python2.6/site-packages/pulp/server/api/consumer.py", line 204, in installpackages
    agent.packages.install(data)
  File "/usr/lib/python2.6/site-packages/pulp/messaging/stub.py", line 69, in __call__
    return self.stub._send(request, opts)
  File "/usr/lib/python2.6/site-packages/pulp/messaging/stub.py", line 111, in _send
    any=opts.any)
  File "/usr/lib/python2.6/site-packages/pulp/messaging/policy.py", line 120, in send
    self.__getstarted(sn)
  File "/usr/lib/python2.6/site-packages/pulp/messaging/policy.py", line 128, in __getstarted
    raise RequestTimeout(sn)
RequestTimeout: 42bb4b72-3a8b-47b3-b6df-a63edd17894b
Comment 11 Pradeep Kilambi 2010-08-30 18:19:14 UTC 
This looks like agent cannot talk to pulpd. make sure your pulpd is running. Timeouts are almost always setup issues.
Comment 12 Pradeep Kilambi 2010-08-30 19:06:48 UTC 
can you paste me the output of

$ openssl x509 -in /etc/pki/consumer/cert.pem  -text|grep CN

Wonder if the cert generation is not setting the CN correctly. Your request says

RequestTimeout: 42bb4b72-3a8b-47b3-b6df-a63edd17894b

Which is not what the CN of the cert has on mine.. CN of the cert has user id
Comment 13 Preethi Thomas 2010-08-30 19:41:19 UTC 
[root@preethi ~]# openssl x509 -in /etc/pki/consumer/cert.pem  -text|grep CN
        Issuer: CN=localhost
        Subject: CN=preethi.usersys.redhat.com
[root@preethi ~]# 
[root@preethi ~]# 
[root@preethi ~]# 
[root@preethi ~]# /etc/init.d/pulpd status
pulpd (18576) is running.
[root@preethi ~]# 
[root@preethi ~]# openssl x509 -in /etc/pki/consumer/cert.pem  -text|grep CN        Issuer: CN=localhost
        Subject: CN=preethi.usersys.redhat.com
[root@preethi ~]# pulp-admin package install -n zsh --consumerid=preethi.usersys.redhat.com
"Traceback (most recent call last):\n  File \"/usr/lib/python2.6/site-packages/pulp/server/webservices/controllers/base.py\", line 51, in report_error\n    return method(self, *args, **kwargs)\n  File \"/usr/lib/python2.6/site-packages/pulp/server/webservices/controllers/consumers.py\", line 310, in POST\n    return action(id)\n  File \"/usr/lib/python2.6/site-packages/pulp/server/webservices/role_check.py\", line 106, in check_roles\n    result = f(instance, *fargs, **kw)\n  File \"/usr/lib/python2.6/site-packages/pulp/server/webservices/controllers/consumers.py\", line 262, in installpackages\n    return self.ok(api.installpackages(id, names))\n  File \"/usr/lib/python2.6/site-packages/pulp/server/auditing.py\", line 186, in _audit\n    result = method(*args, **kwargs)\n  File \"/usr/lib/python2.6/site-packages/pulp/server/api/consumer.py\", line 204, in installpackages\n    agent.packages.install(data)\n  File \"/usr/lib/python2.6/site-packages/pulp/messaging/stub.py\", line 69, in __call__\n    return self.stub._send(request, opts)\n  File \"/usr/lib/python2.6/site-packages/pulp/messaging/stub.py\", line 111, in _send\n    any=opts.any)\n  File \"/usr/lib/python2.6/site-packages/pulp/messaging/policy.py\", line 120, in send\n    self.__getstarted(sn)\n  File \"/usr/lib/python2.6/site-packages/pulp/messaging/policy.py\", line 128, in __getstarted\n    raise RequestTimeout(sn)\nRequestTimeout: ae818264-1d51-4131-9c1c-35962138ad20\n"
[root@preethi ~]#
Comment 14 Pradeep Kilambi 2010-08-30 19:54:50 UTC 
I just tried this case, Initially I got the exact same error as you did:

But one thing I noticed was there was more than one pulpd process running, so I killed all my pulpd processes, freshly started one.

Also make sure /etc/pulp/consumer is same as your CN. If not re-register.

and now I can get the request back to the client. I dont see any timeouts.

$ sudo pulp-admin repo create --id=foo --feed=yum:http://mmccune.fedorapeople.org/pulp/

$ sudo pulp-client consumer create -u admin -p admin --id=foo123

$ sudo pulp-client consumer bind --repoid=foo 

$ sudo pulp-admin package install --consumerid=foo123 -n pulp-test-package

Client logs:


2010-08-30 15:29:07,487 [INFO][foo123] dispatch() @ dispatcher.py:214 - dispatching:{
  "classname": "Packages", 
  "kws": {}, 
  "args": [
    [
      "pulp-test-package"
    ]
  ], 
  "method": "install"
}
2010-08-30 15:29:07,488 [INFO][foo123] install() @ remote.py:62 - installing packages: ['pulp
-test-package']
2010-08-30 15:29:27,634 [INFO][foo123] send() @ producer.py:55 - {a51b8951-c20a-4e45-8fc8-c9c
23e09bcdb} sent (493879ce-1b48-4b9e-b3a2-53454fd4ecdb;{create:always,delete:receiver,node:{ty
pe:queue},link:{durable:True}})
{
  "origin": "a51b8951-c20a-4e45-8fc8-c9c23e09bcdb", 
  "version": "0.1", 
  "sn": "e674c4c8-fdad-4fd2-91e0-218d61f99b71", 
  "any": null, 
}


Although current git has a problem where we cant access the repos on server, which probably not your case as you get a time out even before client sees a request. So jus confirmed its a setup issue. pulpd seems to act strange sometimes. Although thats a broader issue we need to deal with.

So in short I was able to get the server to find client without requesttimeouts.

Moving back to QA.
Comment 15 Preethi Thomas 2010-08-30 20:13:48 UTC 
Like you mentioned yes, I had more than one pulpd process running. I killed all and restarted. That fixed the problem.

verified

[root@preethi ~]# pulp-admin package install -n zsh --consumerid=preethi.usersys.redhat.com
[u'zsh']
Comment 16 Preethi Thomas 2010-09-01 18:56:18 UTC 
moving back to on_qa because of 

https://bugzilla.redhat.com/show_bug.cgi?id=629360
Comment 17 Preethi Thomas 2010-09-10 18:09:17 UTC 
verified

[root@preethi ~]#  pulp-admin -uadmin -padmin package install -n zsh --consumerid=preethi.usersys.redhat.com
Successfully Installed Packages [u'zsh-4.3.10-5.fc13.x86_64', u'zsh-4.3.10-5.fc13.x86_64'] on consumer [preethi.usersys.redhat.com]
[root@preethi ~]# rpm -q zsh
zsh-4.3.10-5.fc13.x86_64
[root@preethi ~]# rpm -qa |grep pulp
pulp-client-0.0.60-1.fc13.noarch
pulp-0.0.60-1.fc13.noarch
pulp-common-0.0.60-1.fc13.noarch
Comment 18 Preethi Thomas 2011-08-16 13:59:05 UTC 
Closing with Community Release 15

pulp-0.0.223-4.