From 4821aaa3a3b5280a70120ea0c5c0a0acef8296c7 Mon Sep 17 00:00:00 2001 From: Bill Erickson Date: Wed, 7 Nov 2012 15:24:19 -0500 Subject: [PATCH] LP#1268619: websocket gateway safer logging Avoid using ap_log_rerror, in particular referencing server->request from the responder thread, since the request_rec will be invalid after on_disconnect is called. --- src/gateway/osrf_websocket_translator.c | 60 ++++++++++++++------------------- 1 file changed, 26 insertions(+), 34 deletions(-) diff --git a/src/gateway/osrf_websocket_translator.c b/src/gateway/osrf_websocket_translator.c index 2e74fa1..b6205d8 100644 --- a/src/gateway/osrf_websocket_translator.c +++ b/src/gateway/osrf_websocket_translator.c @@ -54,12 +54,11 @@ */ #include "httpd.h" -#include "http_log.h" -#include "http_log.h" #include "apr_strings.h" #include "apr_thread_proc.h" #include "apr_hash.h" #include "websocket_plugin.h" +#include "opensrf/log.h" #include "opensrf/osrf_json.h" #include "opensrf/transport_client.h" #include "opensrf/transport_message.h" @@ -92,7 +91,6 @@ static char recipient_buf[RECIP_BUF_SIZE]; // reusable recipient buffer */ void* APR_THREAD_FUNC osrf_responder_thread_main(apr_thread_t *thread, void *data) { - request_rec *r = trans->server->request(trans->server); transport_message *tmsg; jsonObject *msg_wrapper; char *msg_string; @@ -100,18 +98,20 @@ void* APR_THREAD_FUNC osrf_responder_thread_main(apr_thread_t *thread, void *dat while (1) { tmsg = client_recv(osrf_handle, -1); + if (!tmsg) continue; // early exit on interrupt // discard responses received after client disconnect if (!trans->client_connected) { - ap_log_rerror(APLOG_MARK, APLOG_DEBUG, 0, r, + osrfLogDebug(OSRF_LOG_MARK, "WS discarding response for thread=%s, xid=%s", - tmsg->thread, tmsg->osrf_xid); + tmsg->thread, tmsg->osrf_xid); message_free(tmsg); continue; } - ap_log_rerror(APLOG_MARK, APLOG_DEBUG, 0, r, + + osrfLogDebug(OSRF_LOG_MARK, "WS received opensrf response for thread=%s, xid=%s", tmsg->thread, tmsg->osrf_xid); @@ -122,9 +122,10 @@ void* APR_THREAD_FUNC osrf_responder_thread_main(apr_thread_t *thread, void *dat jsonObjectSetKey(msg_wrapper, "osrf_msg", jsonParseRaw(tmsg->body)); if (tmsg->is_error) { - ap_log_rerror(APLOG_MARK, APLOG_ERR, 0, r, + fprintf(stderr, "WS received jabber error message in response to thread=%s and xid=%s", - tmsg->thread, tmsg->osrf_xid); + tmsg->thread, tmsg->osrf_xid); + fflush(stderr); jsonObjectSetKey(msg_wrapper, "transport_error", jsonNewBoolObject(1)); } @@ -140,7 +141,7 @@ void* APR_THREAD_FUNC osrf_responder_thread_main(apr_thread_t *thread, void *dat // a last-touched timeout mechanism to periodically remove old entries if (!apr_hash_get(trans->session_cache, tmsg->thread, APR_HASH_KEY_STRING)) { - ap_log_rerror(APLOG_MARK, APLOG_DEBUG, 0, r, + osrfLogDebug(OSRF_LOG_MARK, "WS caching sender thread=%s, sender=%s", tmsg->thread, tmsg->sender); apr_hash_set(trans->session_cache, @@ -167,7 +168,7 @@ int child_init(const WebSocketServer *server) { apr_threadattr_t *thread_attr = NULL; request_rec *r = server->request(server); - ap_log_rerror(APLOG_MARK, APLOG_DEBUG, 0, r, "WS child_init"); + osrfLogDebug(OSRF_LOG_MARK, "WS child_init"); // osrf_handle will already be connected if this is not the first request // served by this process. @@ -175,7 +176,7 @@ int child_init(const WebSocketServer *server) { char* config_file = "/openils/conf/opensrf_core.xml"; char* config_ctx = "gateway"; //TODO config if (!osrfSystemBootstrapClientResc(config_file, config_ctx, "websocket")) { - ap_log_rerror(APLOG_MARK, APLOG_ERR, 0, r, + osrfLogError(OSRF_LOG_MARK, "WS unable to bootstrap OpenSRF client with config %s", config_file); return 1; } @@ -185,7 +186,7 @@ int child_init(const WebSocketServer *server) { // create a standalone pool for our translator data if (apr_pool_create(&pool, NULL) != APR_SUCCESS) { - ap_log_rerror(APLOG_MARK, APLOG_ERR, 0, r, "WS Unable to create apr_pool"); + osrfLogError(OSRF_LOG_MARK, "WS Unable to create apr_pool"); return 1; } @@ -195,7 +196,7 @@ int child_init(const WebSocketServer *server) { apr_palloc(pool, sizeof(osrfWebsocketTranslator)); if (trans == NULL) { - ap_log_rerror(APLOG_MARK, APLOG_ERR, 0, r, "WS Unable to create translator"); + osrfLogError(OSRF_LOG_MARK, "WS Unable to create translator"); return 1; } @@ -214,8 +215,7 @@ int child_init(const WebSocketServer *server) { trans->responder_thread = thread; } else { - ap_log_rerror(APLOG_MARK, APLOG_ERR, 0, r, - "WS unable to create responder thread"); + osrfLogError(OSRF_LOG_MARK, "WS unable to create responder thread"); return 1; } @@ -229,7 +229,7 @@ void* CALLBACK on_connect_handler(const WebSocketServer *server) { request_rec *r = server->request(server); apr_pool_t *pool; - ap_log_rerror(APLOG_MARK, APLOG_DEBUG, 0, r, + osrfLogDebug(OSRF_LOG_MARK, "WS connect from %s", r->connection->remote_ip); //"WS connect from %s", r->connection->client_ip); // apache 2.4 @@ -242,8 +242,7 @@ void* CALLBACK on_connect_handler(const WebSocketServer *server) { // create a standalone pool for the session cache values, which will be // destroyed on client disconnect. if (apr_pool_create(&pool, trans->main_pool) != APR_SUCCESS) { - ap_log_rerror(APLOG_MARK, APLOG_ERR, 0, r, - "WS Unable to create apr_pool"); + osrfLogError(OSRF_LOG_MARK, "WS Unable to create apr_pool"); return NULL; } @@ -251,8 +250,7 @@ void* CALLBACK on_connect_handler(const WebSocketServer *server) { trans->session_cache = apr_hash_make(trans->session_pool); if (trans->session_cache == NULL) { - ap_log_rerror(APLOG_MARK, APLOG_ERR, 0, r, - "WS unable to create session cache"); + osrfLogError(OSRF_LOG_MARK, "WS unable to create session cache"); return NULL; } @@ -282,8 +280,7 @@ static size_t CALLBACK on_message_handler(void *data, if (buffer_size <= 0) return OK; - ap_log_rerror(APLOG_MARK, APLOG_DEBUG, 0, r, - "WS received message size=%d", buffer_size); + osrfLogDebug(OSRF_LOG_MARK, "WS received message size=%d", buffer_size); // buffer may not be \0-terminated, which jsonParse requires char buf[buffer_size + 1]; @@ -293,8 +290,7 @@ static size_t CALLBACK on_message_handler(void *data, msg_wrapper = jsonParseRaw(buf); if (msg_wrapper == NULL) { - ap_log_rerror(APLOG_MARK, - APLOG_NOTICE, 0, r, "WS Invalid JSON: %s", buf); + osrfLogWarning(OSRF_LOG_MARK, "WS Invalid JSON: %s", buf); return HTTP_BAD_REQUEST; } @@ -313,8 +309,7 @@ static size_t CALLBACK on_message_handler(void *data, // use the caller-provide log trace id if (strlen(log_xid) > MAX_THREAD_SIZE) { - ap_log_rerror(APLOG_MARK, APLOG_NOTICE, - 0, r, "WS log_xid exceeds max length"); + osrfLogWarning(OSRF_LOG_MARK, "WS log_xid exceeds max length"); return HTTP_BAD_REQUEST; } @@ -330,8 +325,7 @@ static size_t CALLBACK on_message_handler(void *data, if (thread) { if (strlen(thread) > MAX_THREAD_SIZE) { - ap_log_rerror(APLOG_MARK, APLOG_NOTICE, - 0, r, "WS thread exceeds max length"); + osrfLogWarning(OSRF_LOG_MARK, "WS thread exceeds max length"); return HTTP_BAD_REQUEST; } @@ -341,8 +335,7 @@ static size_t CALLBACK on_message_handler(void *data, trans->session_cache, thread, APR_HASH_KEY_STRING); if (recipient) { - ap_log_rerror(APLOG_MARK, APLOG_DEBUG, 0, r, - "WS found cached recipient %s", recipient); + osrfLogDebug(OSRF_LOG_MARK, "WS found cached recipient %s", recipient); } } @@ -355,14 +348,13 @@ static size_t CALLBACK on_message_handler(void *data, recipient = recipient_buf; } else { - ap_log_rerror(APLOG_MARK, APLOG_NOTICE, - 0, r, "WS Unable to determine recipient"); + osrfLogWarning(OSRF_LOG_MARK, "WS Unable to determine recipient"); return HTTP_BAD_REQUEST; } } // TODO: activity log entry? -- requires message analysis - ap_log_rerror(APLOG_MARK, APLOG_DEBUG, 0, r, + osrfLogDebug(OSRF_LOG_MARK, "WS relaying message thread=%s, xid=%s, recipient=%s", thread, osrfLogGetXid(), recipient); @@ -398,7 +390,7 @@ void CALLBACK on_disconnect_handler( trans->session_cache = NULL; request_rec *r = server->request(server); - ap_log_rerror(APLOG_MARK, APLOG_DEBUG, 0, r, + osrfLogDebug(OSRF_LOG_MARK, "WS disconnect from %s", r->connection->remote_ip); //"WS disconnect from %s", r->connection->client_ip); // apache 2.4 } -- 2.11.0