From 20bc8b17d60373c2c93ab6bb777d19dd92ed2960 Mon Sep 17 00:00:00 2001 From: Adam Dickmeiss Date: Thu, 7 Mar 2013 10:55:47 +0100 Subject: [PATCH] Use session_log when possible --- src/http_command.c | 142 +++++++++++++++++++++++++++++++--------------------- src/session.c | 22 +++++--- 2 files changed, 98 insertions(+), 66 deletions(-) diff --git a/src/http_command.c b/src/http_command.c index 7620e92..cbe09aa 100644 --- a/src/http_command.c +++ b/src/http_command.c @@ -176,9 +176,13 @@ struct http_session *http_session_create(struct conf_service *service, http_sessions->session_list = r; yaz_mutex_leave(http_sessions->mutex); - r->timeout_iochan = iochan_create(-1, session_timeout, 0, "http_session_timeout"); + r->timeout_iochan = iochan_create(-1, session_timeout, 0, + "http_session_timeout"); iochan_setdata(r->timeout_iochan, r); - yaz_log(http_sessions->log_level, "Session %u created. timeout chan=%p timeout=%d", sesid, r->timeout_iochan, service->session_timeout); + + session_log(r->psession, http_sessions->log_level, + "HTTP session create. timeout chan=%p ses=%d", + r->timeout_iochan, service->session_timeout); iochan_settimeout(r->timeout_iochan, service->session_timeout); iochan_add(service->server->iochan_man, r->timeout_iochan); @@ -192,7 +196,8 @@ void http_session_destroy(struct http_session *s) http_sessions_t http_sessions = s->http_sessions; - yaz_log(http_sessions->log_level, "Session %u destroy", s->session_id); + session_log(s->psession, http_sessions->log_level, + "HTTP session destroy"); yaz_mutex_enter(http_sessions->mutex); /* only if http_session has no active http sessions on it can be destroyed */ if (s->destroy_counter == s->activity_counter) @@ -209,15 +214,17 @@ void http_session_destroy(struct http_session *s) yaz_mutex_leave(http_sessions->mutex); if (must_destroy) { /* destroying for real */ - yaz_log(http_sessions->log_level, "Session %u destroyed", s->session_id); + session_log(s->psession, http_sessions->log_level, "About to destroyd"); iochan_destroy(s->timeout_iochan); session_destroy(s->psession); http_session_use(-1); nmem_destroy(s->nmem); } - else { - yaz_log(http_sessions->log_level, "Session %u destroying delayed. Active clients (%d-%d). Waiting for new timeout.", - s->session_id, s->activity_counter, s->destroy_counter); + else + { + session_log(s->psession, http_sessions->log_level, + "Destroy delayed. Active clients (%d-%d)", + s->activity_counter, s->destroy_counter); } } @@ -454,11 +461,10 @@ static void cmd_init(struct http_channel *c) sesid = make_sessionid(); s = http_session_create(service, c->http_sessions, sesid); - yaz_log(c->http_sessions->log_level, "Session init %u ", sesid); if (!clear || *clear == '0') session_init_databases(s->psession); else - yaz_log(YLOG_LOG, "Session %u init: No databases preloaded", sesid); + session_log(s->psession, YLOG_LOG, "No databases preloaded"); if (process_settings(s->psession, c->request, c->response) < 0) return; @@ -546,9 +552,8 @@ static void termlist_response(struct http_channel *c, struct http_session *s, co response_open_no_status(c, "termlist"); /* new protocol add a status to response. Triggered by a status parameter */ - if (cmd_status != 0) { + if (cmd_status != 0) wrbuf_printf(c->wrbuf, "%s\n", cmd_status); - } wrbuf_printf(c->wrbuf, "%d\n", status); perform_termlist(c, s->psession, name, num, version); @@ -565,8 +570,10 @@ static void termlist_result_ready(void *data) struct http_session *s = locate_session(c); if (report && !strcmp("status", report)) status = "OK"; - if (s) { - yaz_log(c->http_sessions->log_level, "Session %u termlist watch released", s->session_id); + if (s) + { + session_log(s->psession, c->http_sessions->log_level, + "termlist watch released"); termlist_response(c, s, status); release_session(c,s); } @@ -583,11 +590,14 @@ static void cmd_termlist(struct http_channel *c) int report_error = 0; const char *status_message = 0; int active_clients; - if (report && !strcmp("error", report)) { + + if (report && !strcmp("error", report)) + { report_error = 1; status_message = "OK"; } - if (report && !strcmp("status", report)) { + if (report && !strcmp("status", report)) + { report_status = 1; status_message = "OK"; } @@ -601,22 +611,23 @@ static void cmd_termlist(struct http_channel *c) if (session_set_watch(s->psession, SESSION_WATCH_TERMLIST, termlist_result_ready, c, c) != 0) { - yaz_log(YLOG_WARN, "Session %u: Attempt to block multiple times on termlist block. Not supported!", s->session_id); + session_log(s->psession, YLOG_WARN, "Attempt to block " + "multiple times on termlist block. Not supported!"); if (report_error) { error(rs, PAZPAR2_ALREADY_BLOCKED, "termlist"); release_session(c, s); return; } - else if (report_status) { + else if (report_status) status_message = "WARNING (Already blocked on termlist)"; - } - else { - yaz_log(YLOG_WARN, "Session %u: Ignoring termlist block. Return current result", s->session_id); - } + else + session_log(s->psession, YLOG_WARN, + "Ignoring termlist block. Return current result"); } else { - yaz_log(c->http_sessions->log_level, "Session %u: Blocking on command termlist", s->session_id); + session_log(s->psession, c->http_sessions->log_level, + "Blocking on command termlist"); release_session(c, s); return; } @@ -709,7 +720,8 @@ static void bytarget_response(struct http_channel *c, struct http_session *s, co } if (count == 0) - yaz_log(YLOG_WARN, "Empty bytarget Response. No targets found!"); + session_log(s->psession, YLOG_WARN, + "Empty bytarget Response. No targets found!"); for (i = 0; i < count; i++) { wrbuf_puts(c->wrbuf, "\n"); @@ -767,14 +779,16 @@ static void bytarget_result_ready(void *data) struct http_channel *c = (struct http_channel *) data; struct http_session *s = locate_session(c); const char *status_message = "OK"; - if (s) { - yaz_log(c->http_sessions->log_level, "Session %u: bytarget watch released", s->session_id); + if (s) + { + session_log(s->psession, c->http_sessions->log_level, + "bytarget watch released"); bytarget_response(c, s, status_message); release_session(c, s); } - else { - yaz_log(c->http_sessions->log_level, "No Session found for released bytarget watch"); - } + else + yaz_log(c->http_sessions->log_level, + "No Session found for released bytarget watch"); } @@ -790,39 +804,40 @@ static void cmd_bytarget(struct http_channel *c) const char *status_message = "OK"; int no_active; - if (report && !strcmp("error", report)) { + if (report && !strcmp("error", report)) report_error = 1; - } - if (report && !strcmp("status", report)) { + if (report && !strcmp("status", report)) report_status = 1; - } if (!s) return; no_active = session_active_clients(s->psession); - if (block && !strcmp("1",block) && no_active) + if (block && !strcmp("1", block) && no_active) { // if there is already a watch/block. we do not block this one if (session_set_watch(s->psession, SESSION_WATCH_BYTARGET, bytarget_result_ready, c, c) != 0) { - yaz_log(YLOG_WARN, "Session %u: Attempt to block multiple times on bytarget block. Not supported!", s->session_id); - if (report_error) { + session_log(s->psession, YLOG_WARN, "Attempt to block " + "multiple times on bytarget block. Not supported!"); + if (report_error) + { error(rs, PAZPAR2_ALREADY_BLOCKED, "bytarget"); release_session(c, s); return; } - else if (report_status) { + else if (report_status) status_message = "WARNING (Already blocked on bytarget)"; - } else { - yaz_log(YLOG_WARN, "Session %u: Ignoring bytarget block. Return current result.", s->session_id); + session_log(s->psession, YLOG_WARN, "Ignoring bytarget block." + " Return current result."); } } else { - yaz_log(c->http_sessions->log_level, "Session %u: Blocking on command bytarget", s->session_id); + session_log(s->psession, c->http_sessions->log_level, + "Blocking on command bytarget"); release_session(c, s); return; } @@ -1062,8 +1077,10 @@ static void cmd_record_ready(void *data) { struct http_channel *c = (struct http_channel *) data; struct http_session *s = locate_session(c); - if (s) { - yaz_log(c->http_sessions->log_level, "Session %u: record watch released", s->session_id); + if (s) + { + session_log(s->psession, c->http_sessions->log_level, + "record watch released"); show_record(c, s); release_session(c,s); } @@ -1174,8 +1191,10 @@ static void show_records_ready(void *data) { struct http_channel *c = (struct http_channel *) data; struct http_session *s = locate_session(c); - if (s) { - yaz_log(c->http_sessions->log_level, "Session %u: show watch released", s->session_id); + if (s) + { + session_log(s->psession, c->http_sessions->log_level, + "show watch released"); show_records(c, s, -1); } else { @@ -1226,23 +1245,27 @@ static void cmd_show(struct http_channel *c) if (session_set_watch(s->psession, SESSION_WATCH_SHOW_PREF, show_records_ready, c, c) == 0) { - yaz_log(c->http_sessions->log_level, - "Session %u: Blocking on command show (preferred targets)", s->session_id); + session_log(s->psession, c->http_sessions->log_level, + "Blocking on command show (preferred targets)"); release_session(c, s); return; } else { - yaz_log(YLOG_WARN, "Session %u: Attempt to block multiple times on show (preferred targets) block. Not supported!", - s->session_id); - if (report_error) { - error(rs, PAZPAR2_ALREADY_BLOCKED, "show (preferred targets)"); + session_log(s->psession, YLOG_WARN, "Attempt to block" + " multiple times on show (preferred targets) block." + " Not supported!"); + if (report_error) + { + error(rs, PAZPAR2_ALREADY_BLOCKED, + "show (preferred targets)"); release_session(c, s); return; } - else { - yaz_log(YLOG_WARN, "Session %u: Ignoring show(preferred) block. Returning current result.", s->session_id); - } + else + session_log(s->psession, YLOG_WARN, + "Ignoring show(preferred) block." + " Returning current result"); } } @@ -1252,19 +1275,22 @@ static void cmd_show(struct http_channel *c) if (session_set_watch(s->psession, SESSION_WATCH_SHOW, show_records_ready, c, c) != 0) { - yaz_log(YLOG_WARN, "Session %u: Attempt to block multiple times on show block. Not supported!", s->session_id); - if (report_error) { + session_log(s->psession, YLOG_WARN, "Attempt to block" + " multiple times on show block. Not supported!"); + if (report_error) + { error(rs, PAZPAR2_ALREADY_BLOCKED, "show"); release_session(c, s); return; } - else { - yaz_log(YLOG_WARN, "Session %u: Ignoring show block. Returning current result.", s->session_id); - } + else + session_log(s->psession, YLOG_WARN, "Ignoring show block." + " Returning current result"); } else { - yaz_log(c->http_sessions->log_level, "Session %u: Blocking on command show", s->session_id); + session_log(s->psession, c->http_sessions->log_level, + "Blocking on command show"); release_session(c, s); return; } diff --git a/src/session.c b/src/session.c index d8567ee..fbcd94e 100644 --- a/src/session.c +++ b/src/session.c @@ -57,7 +57,7 @@ Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA #include #include -#define USE_TIMING 0 +#define USE_TIMING 1 #if USE_TIMING #include #endif @@ -181,7 +181,8 @@ static void session_normalize_facet(struct session *s, const char *type, prt = pp2_charset_token_create(service->charsets, icu_chain_id); if (!prt) { - yaz_log(YLOG_FATAL, "Unknown ICU chain '%s' for facet of type '%s'", + session_log(s, YLOG_FATAL, + "Unknown ICU chain '%s' for facet of type '%s'", icu_chain_id, type); wrbuf_destroy(facet_wrbuf); wrbuf_destroy(display_wrbuf); @@ -653,11 +654,12 @@ static void session_sort_unlocked(struct session *se, struct reclist_sortparms * int type = sp->type; int clients_research = 0; - yaz_log(YLOG_DEBUG, "session_sort field=%s increasing=%d type=%d", field, increasing, type); + session_log(se, YLOG_DEBUG, "session_sort field=%s increasing=%d type=%d", + field, increasing, type); /* see if we already have sorted for this criteria */ for (sr = se->sorted_results; sr; sr = sr->next) { - if (!reclist_sortparms_cmp(sr,sp)) + if (!reclist_sortparms_cmp(sr, sp)) break; } if (sr) @@ -681,7 +683,9 @@ static void session_sort_unlocked(struct session *se, struct reclist_sortparms * clients_research += client_parse_sort(cl, sp); } if (clients_research) { - yaz_log(YLOG_DEBUG, "Reset results due to %d clients researching", clients_research); + session_log(se, YLOG_DEBUG, + "Reset results due to %d clients researching", + clients_research); session_clear_set(se, sp); } else { @@ -706,7 +710,8 @@ static void session_sort_unlocked(struct session *se, struct reclist_sortparms * client_start_search(cl); } else { - yaz_log(YLOG_DEBUG, "Client %s: No re-start/ingest in show. Wrong client state: %d", + session_log(se, YLOG_DEBUG, + "Client %s: No re-start/ingest in show. Wrong client state: %d", client_get_id(cl), client_get_state(cl)); } @@ -1338,7 +1343,7 @@ struct record_cluster **show_range_start(struct session *se, reclist_leave(se->reclist); #if USE_TIMING yaz_timing_stop(t); - yaz_log(YLOG_LOG, "show %6.5f %3.2f %3.2f", + session_log(se, YLOG_LOG, "show %6.5f %3.2f %3.2f", yaz_timing_get_real(t), yaz_timing_get_user(t), yaz_timing_get_sys(t)); yaz_timing_destroy(&t); @@ -1932,7 +1937,8 @@ static int ingest_to_cluster(struct client *cl, int hits = (int) client_get_hits(cl); term_factor = MAX(hits, maxrecs) / MAX(1, maxrecs); assert(term_factor >= 1); - yaz_log(YLOG_DEBUG, "Using term factor: %d (%d / %d)", term_factor, MAX(hits, maxrecs), MAX(1, maxrecs)); + session_log(se, YLOG_DEBUG, "Using term factor: %d (%d / %d)", + term_factor, MAX(hits, maxrecs), MAX(1, maxrecs)); } } -- 1.7.10.4