Bug 710003

Summary: Internal Server Error: after upgrading the pulp-rhui setup
Product: Red Hat Update Infrastructure for Cloud Providers Reporter: Sachin Ghai <sghai>
Component: ToolsAssignee: Jay Dobies <jason.dobies>
Status: CLOSED UPSTREAM QA Contact: wes hayutin <whayutin>
Severity: urgent Docs Contact:
Priority: unspecified    
Version: 2.0CC: kbidarka, sghai, tsanders
Target Milestone: ---   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2011-06-02 12:47:55 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 Sachin Ghai 2011-06-02 08:47:01 UTC
Description of problem:
I upgraded the pulp setup using yum update. Also updated the rh-rhui-tools.
Then I generated rhua/cds config rpms using new answer file. Installed all config rpms on respective nodes ( rhua/cds).

While Installing rhua config rpm, got an error due to multiple occurrences of ssl certs in qpidd.conf. I fixed it by manully updating the file.

---------------------------------------------------------------------------
[root@dhcp193-79 ~]# rpm -ivh rh-rhua-config-2.0-2.el6.noarch.rpm 
Preparing...                ########################################### [100%]
   1:rh-rhua-config         ########################################### [100%]
Updating RHUA Server Configuration
Updating RHUA Repository Authentication Configuration
Updating Apache SSL Configuration
data model in use matches the current version
database migration to version 14 complete
Stopping httpd: [FAILED]
Stopping Qpid AMQP daemon: [FAILED]
Stopping mongod: [  OK  ]
Starting mongod: [  OK  ]
Starting Qpid AMQP daemon: [  OK  ]
Starting httpd: [  OK  ]
----------------------------------------------------------------------------

Then I ran following two services. Both went well, and restarted all the deamons successfuly.
- service pulp-server init
- service pulp-server restart

----------------------------------------------------------------------------
[root@dhcp193-79 mongodb]# service pulp-server init
data model in use matches the current version
database migration to version 14 complete
[root@dhcp193-79 mongodb]# service pulp-server restart
Stopping httpd:                                            [  OK  ]
Stopping Qpid AMQP daemon:                                 [  OK  ]
Stopping mongod:                                           [  OK  ]
Starting mongod:                                           [  OK  ]
Starting Qpid AMQP daemon:                                 [  OK  ]
Starting httpd:                                            [  OK  ]

-------------------------------------------------------------------------------

When I started rhui-manager, I got following traceback:

-------------------------------------------------------------------------------
[root@dhcp193-100 rhui]# rhui-manager 
Previous authentication credentials could not be found. Logging into
the RHUI.

If this is the first time using the RHUI, it is recommended to change
the user's password in the User Management section of RHUI Tools.

RHUI Username: admin
RHUI Password: 
Traceback (most recent call last):
  File "/usr/bin/rhui-manager", line 16, in <module>
    rhui.tools.launcher.main()
  File "/usr/lib/python2.6/site-packages/rhui/tools/launcher.py", line 323, in main
    pulp_api = _pulp_api(config, prompt, values.username, values.password)
  File "/usr/lib/python2.6/site-packages/rhui/tools/launcher.py", line 114, in _pulp_api
    auth.login(pulp_api, prompt)
  File "/usr/lib/python2.6/site-packages/rhui/tools/auth.py", line 67, in login
    credentials = _login(pulp, prompt)
  File "/usr/lib/python2.6/site-packages/rhui/tools/auth.py", line 120, in _login
    raise e
pulp.client.server.ServerRequestError: (500, '<!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">\n<html><head>\n<title>500 Internal Server Error</title>\n</head><body>\n<h1>Internal Server Error</h1>\n<p>The server encountered an internal error or\nmisconfiguration and was unable to complete\nyour request.</p>\n<p>Please contact the server administrator,\n root@localhost and inform them of the time the error occurred,\nand anything you might have done that may have\ncaused the error.</p>\n<p>More information about this error may be available\nin the server error log.</p>\n<hr>\n<address>Apache/2.2.15 (Red Hat) Server at dhcp193-79.pnq.redhat.com Port 443</address>\n</body></html>\n', None)

----------------------------------------------------------------------------

Version-Release number of selected component (if applicable):
pulp 0.185
rh-rhui-tools 2.0.26

How reproducible:
always

Steps to Reproduce:
1. upgraded the setup from 
pulp 0.181 to pulp 0.185 and 
rhui 2.0.25 to 2.0.26


  
Actual results:
Insternal server Error while running rhui-manager

Expected results:


Additional info:

Comment 1 Sachin Ghai 2011-06-02 08:53:47 UTC
I removed following two files:
- mongod from /var/lock/subsys
- mongod.lock from /var/lib/mongod

Intiatlized pulp-server and restart it.:

-----------------------------
[root@dhcp193-79 subsys]# rm mongod 
rm: remove regular empty file `mongod'? y
[root@dhcp193-79 subsys]# service pulp-server init
data model in use matches the current version
database migration to version 14 complete
[root@dhcp193-79 subsys]# service pulp-server restart
Stopping httpd:                                            [  OK  ]
Stopping Qpid AMQP daemon:                                 [  OK  ]
Stopping mongod:                                           [  OK  ]
Starting mongod:                                           [  OK  ]
Starting Qpid AMQP daemon:                                 [  OK  ]
Starting httpd:                                            [  OK  ]
--------------------------------

Then tried "repo list" using "pulp cli", its also throwing same error.

------------------
[root@dhcp193-79 mongodb]# pulp-admin -u admin -p admin repo list
error: operation failed: <!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 (Red Hat) Server at dhcp193-79.pnq.redhat.com Port 443</address>
</body></html>
-------------------


apache ssl_error_logs says:
==============================


[root@dhcp193-79 subsys]# tail -f /var/log/httpd/ssl_error_log
[Thu Jun 02 13:49:50 2011] [error] [client 10.65.193.100] mod_wsgi (pid=31646): Target WSGI script '/srv/pulp/webservices.wsgi' cannot be loaded as Python module.
[Thu Jun 02 13:49:50 2011] [error] [client 10.65.193.100] mod_wsgi (pid=31646): Exception occurred processing WSGI script '/srv/pulp/webservices.wsgi'.
[Thu Jun 02 13:49:50 2011] [error] [client 10.65.193.100] Traceback (most recent call last):
[Thu Jun 02 13:49:50 2011] [error] [client 10.65.193.100]   File "/srv/pulp/webservices.wsgi", line 20, in <module>
[Thu Jun 02 13:49:50 2011] [error] [client 10.65.193.100]     application = wsgi_application()
[Thu Jun 02 13:49:50 2011] [error] [client 10.65.193.100]   File "/usr/lib/python2.6/site-packages/pulp/server/webservices/application.py", line 94, in wsgi_application
[Thu Jun 02 13:49:50 2011] [error] [client 10.65.193.100]     _initialize_pulp()
[Thu Jun 02 13:49:50 2011] [error] [client 10.65.193.100]   File "/usr/lib/python2.6/site-packages/pulp/server/webservices/application.py", line 83, in _initialize_pulp
[Thu Jun 02 13:49:50 2011] [error] [client 10.65.193.100]     scheduled_sync.init_scheduled_syncs()
[Thu Jun 02 13:49:50 2011] [error] [client 10.65.193.100]   File "/usr/lib/python2.6/site-packages/pulp/server/api/scheduled_sync.py", line 223, in init_scheduled_syncs
[Thu Jun 02 13:49:50 2011] [error] [client 10.65.193.100]     _init_repo_scheduled_syncs()
[Thu Jun 02 13:49:50 2011] [error] [client 10.65.193.100]   File "/usr/lib/python2.6/site-packages/pulp/server/api/scheduled_sync.py", line 231, in _init_repo_scheduled_syncs
[Thu Jun 02 13:49:50 2011] [error] [client 10.65.193.100]     _add_repo_scheduled_sync_task(repo)
[Thu Jun 02 13:49:50 2011] [error] [client 10.65.193.100]   File "/usr/lib/python2.6/site-packages/pulp/server/api/scheduled_sync.py", line 107, in _add_repo_scheduled_sync_task
[Thu Jun 02 13:49:50 2011] [error] [client 10.65.193.100]     synchronizer = api.get_synchronizer(repo['source']['type'])
[Thu Jun 02 13:49:50 2011] [error] [client 10.65.193.100] AttributeError: 'RepoApi' object has no attribute 'get_synchronizer'


apache_error_log says:
====================
[root@dhcp193-79 subsys]# tail -f /var/log/httpd/error_log
[Thu Jun 02 13:49:50 2011] [error] /usr/lib/python2.6/site-packages/oauth2/__init__.py:29: DeprecationWarning: the sha module is deprecated; use the hashlib module instead
[Thu Jun 02 13:49:50 2011] [error]   import sha
[Thu Jun 02 13:49:50 2011] [error] /usr/lib/python2.6/site-packages/httplib2/__init__.py:29: DeprecationWarning: the md5 module is deprecated; use hashlib instead
[Thu Jun 02 13:49:50 2011] [error]   import md5

Comment 2 Sachin Ghai 2011-06-02 10:50:18 UTC
segfault in /var/log/messages of rhua server :
===========================================
Jun  2 13:49:39 dhcp193-79 kernel: httpd[31530]: segfault at 8 ip 00007f511c914484 sp 00007f50f35fcfe0 error 4 in libpython2.6.so.1.0[7f511c882000+170000]
Jun  2 13:49:39 dhcp193-79 qpidd[31466]: 2011-06-02 13:49:39 notice Shut down
Jun  2 13:49:40 dhcp193-79 qpidd[31616]: 2011-06-02 13:49:40 notice Listening on TCP port 5672
Jun  2 13:49:40 dhcp193-79 qpidd[31616]: 2011-06-02 13:49:40 notice Listening for SSL connections on TCP port 5674
Jun  2 13:49:40 dhcp193-79 qpidd[31616]: 2011-06-02 13:49:40 notice Broker running

Comment 3 Sachin Ghai 2011-06-02 12:32:57 UTC
Earlier I upgrade the existing setup with new builds.

Now I just configured fresh setup (Installed everything from scratch) and this issue is also reproducible on fresh setup. 


After installing new setup, I added two repos. After adding two new repos via using rhui-manager, I got same traceback in pulp.log. Earlier (during upgrade), I got this error in ssl_error_log.an


pulp.log:
========
2011-06-02 17:50:20,526 [INFO][Dummy-2] _write_cert_bundle() @ repo_cert_utils.py:349 - Storing repo cert file [/etc/pki/content/rhui-1.2-5Server-x86_64/feed-rhui-1.2-5Server-x86_64.ca]
2011-06-02 17:50:20,527 [INFO][Dummy-2] _write_cert_bundle() @ repo_cert_utils.py:349 - Storing repo cert file [/etc/pki/content/rhui-1.2-5Server-x86_64/feed-rhui-1.2-5Server-x86_64.cert]
2011-06-02 17:50:20,527 [INFO][Dummy-2] _write_cert_bundle() @ repo_cert_utils.py:349 - Storing repo cert file [/etc/pki/content/rhui-1.2-5Server-x86_64/feed-rhui-1.2-5Server-x86_64.key]
2011-06-02 17:50:20,527 [INFO][Dummy-2] _write_cert_bundle() @ repo_cert_utils.py:349 - Storing repo cert file [/etc/pki/content/rhui-1.2-5Server-x86_64/consumer-rhui-1.2-5Server-x86_64.ca]
2011-06-02 17:50:20,528 [INFO][Dummy-2] _write_cert_bundle() @ repo_cert_utils.py:349 - Storing repo cert file [/etc/pki/content/rhui-1.2-5Server-x86_64/consumer-rhui-1.2-5Server-x86_64.cert]
2011-06-02 17:50:20,528 [INFO][Dummy-2] _write_cert_bundle() @ repo_cert_utils.py:349 - Storing repo cert file [/etc/pki/content/rhui-1.2-5Server-x86_64/consumer-rhui-1.2-5Server-x86_64.key]
2011-06-02 17:50:20,547 [ERROR][Dummy-2] report_error() @ base.py:57 - Traceback (most recent call last):
  File "/usr/lib/python2.6/site-packages/pulp/server/webservices/controllers/base.py", line 53, in report_error
    return method(self, *args, **kwargs)
  File "/usr/lib/python2.6/site-packages/pulp/server/webservices/controllers/base.py", line 132, in _auth_decorator
    value = method(self, *args, **kwargs)
  File "/usr/lib/python2.6/site-packages/pulp/server/webservices/controllers/repositories.py", line 217, in POST
    notes=repo_data.get('notes', None))
  File "/usr/lib/python2.6/site-packages/pulp/server/auditing.py", line 197, in _audit
    result = method(*args, **kwargs)
  File "/usr/lib/python2.6/site-packages/pulp/server/api/repo.py", line 214, in create
    update_repo_schedule(r, sync_schedule)
  File "/usr/lib/python2.6/site-packages/pulp/server/api/scheduled_sync.py", line 178, in update_repo_schedule
    _add_repo_scheduled_sync_task(repo)
  File "/usr/lib/python2.6/site-packages/pulp/server/api/scheduled_sync.py", line 107, in _add_repo_scheduled_sync_task
    synchronizer = api.get_synchronizer(repo['source']['type'])
AttributeError: 'RepoApi' object has no attribute 'get_synchronizer'

2011-06-02 17:50:20,692 [INFO][Dummy-5] _write_cert_bundle() @ repo_cert_utils.py:349 - Storing repo cert file [/etc/pki/content/rhui-1.2-5Server-i386/feed-rhui-1.2-5Server-i386.ca]
2011-06-02 17:50:20,692 [INFO][Dummy-5] _write_cert_bundle() @ repo_cert_utils.py:349 - Storing repo cert file [/etc/pki/content/rhui-1.2-5Server-i386/feed-rhui-1.2-5Server-i386.cert]
2011-06-02 17:50:20,693 [INFO][Dummy-5] _write_cert_bundle() @ repo_cert_utils.py:349 - Storing repo cert file [/etc/pki/content/rhui-1.2-5Server-i386/feed-rhui-1.2-5Server-i386.key]
2011-06-02 17:50:20,693 [INFO][Dummy-5] _write_cert_bundle() @ repo_cert_utils.py:349 - Storing repo cert file [/etc/pki/content/rhui-1.2-5Server-i386/consumer-rhui-1.2-5Server-i386.ca]
2011-06-02 17:50:20,693 [INFO][Dummy-5] _write_cert_bundle() @ repo_cert_utils.py:349 - Storing repo cert file [/etc/pki/content/rhui-1.2-5Server-i386/consumer-rhui-1.2-5Server-i386.cert]
2011-06-02 17:50:20,693 [INFO][Dummy-5] _write_cert_bundle() @ repo_cert_utils.py:349 - Storing repo cert file [/etc/pki/content/rhui-1.2-5Server-i386/consumer-rhui-1.2-5Server-i386.key]
2011-06-02 17:50:20,698 [ERROR][Dummy-5] report_error() @ base.py:57 - Traceback (most recent call last):
  File "/usr/lib/python2.6/site-packages/pulp/server/webservices/controllers/base.py", line 53, in report_error
    return method(self, *args, **kwargs)
  File "/usr/lib/python2.6/site-packages/pulp/server/webservices/controllers/base.py", line 132, in _auth_decorator
    value = method(self, *args, **kwargs)
  File "/usr/lib/python2.6/site-packages/pulp/server/webservices/controllers/repositories.py", line 217, in POST
    notes=repo_data.get('notes', None))
  File "/usr/lib/python2.6/site-packages/pulp/server/auditing.py", line 197, in _audit
    result = method(*args, **kwargs)
  File "/usr/lib/python2.6/site-packages/pulp/server/api/repo.py", line 214, in create
    update_repo_schedule(r, sync_schedule)
  File "/usr/lib/python2.6/site-packages/pulp/server/api/scheduled_sync.py", line 178, in update_repo_schedule
    _add_repo_scheduled_sync_task(repo)
  File "/usr/lib/python2.6/site-packages/pulp/server/api/scheduled_sync.py", line 107, in _add_repo_scheduled_sync_task
    synchronizer = api.get_synchronizer(repo['source']['type'])
AttributeError: 'RepoApi' object has no attribute 'get_synchronizer'


I'm raising the severity of this defect as its a blocker defect and I lost two setups :(

Comment 4 Jay Dobies 2011-06-02 12:47:55 UTC
This is a Pulp error and was refiled upstream as 710093.