diff --git a/doc/protocol.txt b/doc/protocol.txt index 3b220e35bb..2f17415c83 100644 --- a/doc/protocol.txt +++ b/doc/protocol.txt @@ -1177,7 +1177,7 @@ The arguments are: address IP and port. Connection close events additionally supply a reason for closing the connection. -- "proxycmds": Emits detailed timing logs about requests/responses being +- "proxyreqs": Emits detailed timing logs about requests/responses being returned to a client while in proxy mode. The conditions which logs are written here may be influenced by configuration. diff --git a/logger.c b/logger.c index 4b026818f0..0ef822c968 100644 --- a/logger.c +++ b/logger.c @@ -304,33 +304,6 @@ static int _logger_parse_cce(logentry *e, char *scratch) { } #ifdef PROXY -static void _logger_log_proxy_raw(logentry *e, const entry_details *d, const void *entry, va_list ap) { - struct timeval start = va_arg(ap, struct timeval); - char *cmd = va_arg(ap, char *); - unsigned short type = va_arg(ap, int); - unsigned short code = va_arg(ap, int); - - struct logentry_proxy_raw *le = (void *)e->data; - struct timeval end; - gettimeofday(&end, NULL); - le->type = type; - le->code = code; - le->elapsed = (end.tv_sec - start.tv_sec) * 1000000 + (end.tv_usec - start.tv_usec); - memcpy(le->cmd, cmd, 9); - e->size = sizeof(struct logentry_proxy_raw); -} - -static int _logger_parse_prx_raw(logentry *e, char *scratch) { - int total; - struct logentry_proxy_raw *le = (void *)e->data; - - total = snprintf(scratch, LOGGER_PARSE_SCRATCH, - "ts=%d.%d gid=%llu type=proxy_raw elapsed=%lu cmd=%s type=%d code=%d\n", - (int) e->tv.tv_sec, (int) e->tv.tv_usec, (unsigned long long) e->gid, - le->elapsed, le->cmd, le->type, le->code); - return total; -} - // TODO (v2): the length caps here are all magic numbers. Haven't thought of // something yet that I like better. // Should at least make a define to the max log len (1024) and do some math @@ -383,7 +356,6 @@ static int _logger_parse_prx_req(logentry *e, char *scratch) { int total; struct logentry_proxy_req *le = (void *)e->data; - // TODO: encode detail / req total = snprintf(scratch, LOGGER_PARSE_SCRATCH, "ts=%d.%d gid=%llu type=proxy_req elapsed=%lu type=%d code=%d status=%d be=%.*s:%.*s detail=%.*s req=%.*s\n", (int) e->tv.tv_sec, (int) e->tv.tv_usec, (unsigned long long) e->gid, @@ -435,8 +407,7 @@ static const entry_details default_entries[] = { [LOGGER_PROXY_CONFIG] = {512, LOG_PROXYEVENTS, _logger_log_text, _logger_parse_text, "type=proxy_conf status=%s" }, - [LOGGER_PROXY_RAW] = {512, LOG_PROXYCMDS, _logger_log_proxy_raw, _logger_parse_prx_raw, NULL}, - [LOGGER_PROXY_REQ] = {1024, LOG_PROXYUSER, _logger_log_proxy_req, _logger_parse_prx_req, NULL}, + [LOGGER_PROXY_REQ] = {1024, LOG_PROXYREQS, _logger_log_proxy_req, _logger_parse_prx_req, NULL}, [LOGGER_PROXY_ERROR] = {512, LOG_PROXYEVENTS, _logger_log_text, _logger_parse_text, "type=proxy_error msg=%s" }, diff --git a/logger.h b/logger.h index 7d532765a9..1d261de178 100644 --- a/logger.h +++ b/logger.h @@ -115,13 +115,6 @@ struct logentry_conn_event { struct sockaddr_in6 addr; }; #ifdef PROXY -struct logentry_proxy_raw { - unsigned short type; - unsigned short code; - long elapsed; // elapsed time in usec - char cmd[8]; -}; - struct logentry_proxy_req { unsigned short type; unsigned short code; @@ -159,7 +152,7 @@ struct _logentry { #define LOG_EVICTIONS (1<<6) /* details of evicted items */ #define LOG_STRICT (1<<7) /* block worker instead of drop */ #define LOG_RAWCMDS (1<<9) /* raw ascii commands */ -#define LOG_PROXYCMDS (1<<10) /* command logs from proxy */ +#define LOG_PROXYREQS (1<<10) /* command logs from proxy */ #define LOG_PROXYEVENTS (1<<11) /* error log stream from proxy */ #define LOG_PROXYUSER (1<<12) /* user generated logs from proxy */ diff --git a/proto_proxy.c b/proto_proxy.c index d557da5960..60c50d6779 100644 --- a/proto_proxy.c +++ b/proto_proxy.c @@ -496,7 +496,7 @@ static void _set_noreply_mode(mc_resp *resp, mcp_resp_t *r) { case RESP_MODE_METAQUIET: if (r->resp.code == MCMC_CODE_MISS) { resp->skip = true; - } else if (r->cmd[1] != 'g' && r->resp.code == MCMC_CODE_OK) { + } else if (r->cmd != CMD_MG && r->resp.code == MCMC_CODE_OK) { // FIXME (v2): mcmc's parser needs to help us out a bit more // here. // This is a broken case in the protocol though; quiet mode @@ -530,7 +530,6 @@ int proxy_run_coroutine(lua_State *Lc, mc_resp *resp, io_pending_proxy_t *p, con int type = lua_type(Lc, 1); if (type == LUA_TUSERDATA) { mcp_resp_t *r = luaL_checkudata(Lc, 1, "mcp.response"); - LOGGER_LOG(NULL, LOG_PROXYCMDS, LOGGER_PROXY_RAW, NULL, r->start, r->cmd, r->resp.type, r->resp.code); _set_noreply_mode(resp, r); if (r->buf) { // response set from C. @@ -806,7 +805,6 @@ static void mcp_queue_io(conn *c, mc_resp *resp, int coro_ref, lua_State *Lc) { memset(r, 0, sizeof(mcp_resp_t)); r->buf = NULL; r->blen = 0; - r->start = rq->start; // need to inherit the original start time. // Set noreply mode. // TODO (v2): the response "inherits" the request's noreply mode, which isn't // strictly correct; we should inherit based on the request that spawned @@ -829,15 +827,7 @@ static void mcp_queue_io(conn *c, mc_resp *resp, int coro_ref, lua_State *Lc) { r->mode = RESP_MODE_NORMAL; } - int x; - int end = rq->pr.reqlen-2 > RESP_CMD_MAX ? RESP_CMD_MAX : rq->pr.reqlen-2; - for (x = 0; x < end; x++) { - if (rq->pr.request[x] == ' ') { - break; - } - r->cmd[x] = rq->pr.request[x]; - } - r->cmd[x] = '\0'; + r->cmd = rq->pr.command; luaL_getmetatable(Lc, "mcp.response"); lua_setmetatable(Lc, -2); diff --git a/proto_text.c b/proto_text.c index 26e8eec764..d794514904 100644 --- a/proto_text.c +++ b/proto_text.c @@ -2291,8 +2291,8 @@ static void process_watch_command(conn *c, token_t *tokens, const size_t ntokens f |= LOG_SYSEVENTS; } else if ((strcmp(tokens[x].value, "connevents") == 0)) { f |= LOG_CONNEVENTS; - } else if ((strcmp(tokens[x].value, "proxycmds") == 0)) { - f |= LOG_PROXYCMDS; + } else if ((strcmp(tokens[x].value, "proxyreqs") == 0)) { + f |= LOG_PROXYREQS; } else if ((strcmp(tokens[x].value, "proxyevents") == 0)) { f |= LOG_PROXYEVENTS; } else if ((strcmp(tokens[x].value, "proxyuser") == 0)) { diff --git a/proxy.h b/proxy.h index 7abec66dce..1c44ef3166 100644 --- a/proxy.h +++ b/proxy.h @@ -364,12 +364,11 @@ enum mcp_resp_mode { #define RESP_CMD_MAX 8 typedef struct { mcmc_resp_t resp; - struct timeval start; // start time inherited from paired request char *buf; // response line + potentially value. size_t blen; // total size of the value to read. int status; // status code from mcmc_read() int bread; // amount of bytes read into value so far. - char cmd[RESP_CMD_MAX+1]; // until we can reverse CMD_*'s to strings directly. + uint8_t cmd; // from parser (pr.command) enum mcp_resp_mode mode; // reply mode (for noreply fixing) char be_name[MAX_NAMELEN+1]; char be_port[MAX_PORTLEN+1]; diff --git a/proxy_await.c b/proxy_await.c index 60cd004e70..ada4d31f8b 100644 --- a/proxy_await.c +++ b/proxy_await.c @@ -97,7 +97,6 @@ static void mcp_queue_await_io(conn *c, lua_State *Lc, mcp_request_t *rq, int aw // reserve one uservalue for a lua-supplied response. mcp_resp_t *r = lua_newuserdatauv(Lc, sizeof(mcp_resp_t), 1); memset(r, 0, sizeof(mcp_resp_t)); - r->start = rq->start; // Set noreply mode. // TODO (v2): the response "inherits" the request's noreply mode, which isn't // strictly correct; we should inherit based on the request that spawned @@ -120,15 +119,7 @@ static void mcp_queue_await_io(conn *c, lua_State *Lc, mcp_request_t *rq, int aw r->mode = RESP_MODE_NORMAL; } - int x; - int end = rq->pr.reqlen-2 > RESP_CMD_MAX ? RESP_CMD_MAX : rq->pr.reqlen-2; - for (x = 0; x < end; x++) { - if (rq->pr.request[x] == ' ') { - break; - } - r->cmd[x] = rq->pr.request[x]; - } - r->cmd[x] = '\0'; + r->cmd = rq->pr.command; luaL_getmetatable(Lc, "mcp.response"); lua_setmetatable(Lc, -2);