| Summary: | [RFE] Report initialisation errors in pulp log as well as Apache log | ||
|---|---|---|---|
| Product: | [Retired] Pulp | Reporter: | Nick Coghlan <ncoghlan> |
| Component: | z_other | Assignee: | Jay Dobies <jason.dobies> |
| Status: | CLOSED CURRENTRELEASE | QA Contact: | Preethi Thomas <pthomas> |
| Severity: | medium | Docs Contact: | |
| Priority: | unspecified | ||
| Version: | 2.0.6 | CC: | jason.dobies |
| Target Milestone: | --- | Keywords: | FutureFeature, Triaged |
| Target Release: | Sprint 42 | ||
| Hardware: | Unspecified | ||
| OS: | Unspecified | ||
| Whiteboard: | |||
| Fixed In Version: | Doc Type: | Enhancement | |
| Doc Text: | Story Points: | --- | |
| Clone Of: | Environment: | ||
| Last Closed: | 2013-01-09 17:04:16 UTC | Type: | --- |
| Regression: | --- | Mount Type: | --- |
| Documentation: | --- | CRM: | |
| Verified Versions: | Category: | --- | |
| oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |
| Cloudforms Team: | --- | Target Upstream Version: | |
At the same time, let's use this opportunity to make it more clear that the server didn't start, similar to what Nick suggested, but I'd like to see it a step further where the initialize call has an enumerated set of exceptions that describe where it failed. QE Verification Notes:
On successful starts, only pulp.log will indicate something like the following:
2012-11-21 10:16:47,374 6538:139703320938560: pulp.server.webservices.application:INFO: application:178 *************************************************************
2012-11-21 10:16:47,374 6538:139703320938560: pulp.server.webservices.application:INFO: application:179 The Pulp server has been successfully initialized
2012-11-21 10:16:47,374 6538:139703320938560: pulp.server.webservices.application:INFO: application:180 *************************************************************
On failed starts, both pulp.log and error_log should indicate the error and traceback. It's ugly to look through based on the logging format (which I may change), but the second line is a description of what went wrong.
2012-11-21 10:16:17,663 6302:140104080852736: pulp.server.webservices.application:CRITICAL: application:164 *************************************************************
2012-11-21 10:16:17,663 6302:140104080852736: pulp.server.webservices.application:CRITICAL: application:165 The Pulp server failed to start due to the following reasons:
2012-11-21 10:16:17,663 6302:140104080852736: pulp.server.webservices.application:ERROR: application:166 One or more plugins failed to initialize. If a new type has been added, run pulp-manage-db to load the type into the database and restart the application.
Traceback (most recent call last):
File "/home/jdob/code/pulp/pulp/platform/src/pulp/server/webservices/application.py", line 162, in wsgi_application
# fails to start (I can't even log in),
File "/home/jdob/code/pulp/pulp/platform/src/pulp/server/webservices/application.py", line 112, in _initialize_pulp
plugin_api.initialize()
File "/home/jdob/code/pulp/pulp/platform/src/pulp/plugins/loader/api.py", line 60, in initialize
assert not _is_initialized()
InitializationException: One or more plugins failed to initialize. If a new type has been added, run pulp-manage-db to load the type into the database and restart the application.
2012-11-21 10:16:17,663 6302:140104080852736: pulp.server.webservices.application:CRITICAL: application:167 *************************************************************
commit 0502f78ff320ee1a8008d4ab381cb6c6f1edba7b commit b6b62def6780fee4780352158d06eb5c00d4c771 Fixed in the 0.9 beta. Failed start in pulp.log
2012-12-11 08:11:40,271 pulp.server.db.connection:INFO: Attempting Database connection with seeds = localhost:27017
2012-12-11 08:11:40,274 pulp.server.db.connection:CRITICAL: Database initialization failed
Successful start
2012-12-11 08:12:12,117 pulp.server.agent.direct.services:INFO: Task reply handler, started.
2012-12-11 08:12:12,117 pulp.server.agent.direct.services:INFO: AMQP reply handler started
2012-12-11 08:12:12,117 pulp.server.webservices.application:INFO: *************************************************************
2012-12-11 08:12:12,118 pulp.server.webservices.application:INFO: The Pulp server has been successfully initialized
2012-12-11 08:12:12,118 pulp.server.webservices.application:INFO: *************************************************************
2012-12-11 08:12:12,218 gofer.messaging.broker:INFO: {preethi-el6-pulp.usersys.redhat.com:5672} connected to AMQP
Failed start in error_log
[Tue Dec 11 08:14:06 2012] [error] 2012-12-11 08:14:06,449 pulp.server.db.connection:CRITICAL: Database initialization failed
[Tue Dec 11 08:14:06 2012] [error] mod_wsgi (pid=27260): Target WSGI script '/srv/pulp/webservices.wsgi' cannot be loaded as Python module.
[Tue Dec 11 08:14:06 2012] [error] mod_wsgi (pid=27260): Exception occurred processing WSGI script '/srv/pulp/webservices.wsgi'.
[Tue Dec 11 08:14:06 2012] [error] Traceback (most recent call last):
[Tue Dec 11 08:14:06 2012] [error] File "/srv/pulp/webservices.wsgi", line 16, in <module>
[Tue Dec 11 08:14:06 2012] [error] from pulp.server.webservices.application import wsgi_application
[Tue Dec 11 08:14:06 2012] [error] File "/usr/lib/python2.6/site-packages/pulp/server/webservices/application.py", line 40, in <module>
[Tue Dec 11 08:14:06 2012] [error] db_connection.initialize()
[Tue Dec 11 08:14:06 2012] [error] File "/usr/lib/python2.6/site-packages/pulp/server/db/connection.py", line 47, in initialize
[Tue Dec 11 08:14:06 2012] [error] _connection = pymongo.Connection(seeds)
[Tue Dec 11 08:14:06 2012] [error] File "/usr/lib64/python2.6/site-packages/pymongo/connection.py", line 381, in __init__
[Tue Dec 11 08:14:06 2012] [error] self.__find_node()
[Tue Dec 11 08:14:06 2012] [error] File "/usr/lib64/python2.6/site-packages/pymongo/connection.py", line 659, in __find_node
[Tue Dec 11 08:14:06 2012] [error] raise AutoReconnect(', '.join(errors))
[Tue Dec 11 08:14:06 2012] [error] AutoReconnect: could not connect to localhost:27017: [Errno 111] Connection refused
success
Tue Dec 11 08:15:01 2012] [notice] Apache/2.2.15 (Unix) DAV/2 mod_ssl/2.2.15 OpenSSL/1.0.0-fips mod_wsgi/3.3 Python/2.6.6 configured -- resuming normal operations
Pulp v2.0 released |
In working on the generic content plugins for Pulp, I forgot that initialisation errors currently only appear in the Apache error log rather than the Pulp log. To make the Pulp log more useful in this case, it would be nice to update pulp.server.webservices.application.wsgi_application to also record the exception in the Pulp log: def wsgi_application(): """ Application factory to create, configure, and return a WSGI application using the web.py framework. @return: wsgi application callable """ application = web.subdir_application(URLS) # TODO make debug configurable stack = ErrorHandlerMiddleware(application.wsgifunc(), debug=True) try: _initialize_pulp() except Exception as exc: _LOG.exception("Failed to initialize Pulp") raise return stack (The new part is the try/except around the initialisation call)