This is an automated email from the ASF dual-hosted git repository. shinrich pushed a commit to branch master in repository https://gitbox.apache.org/repos/asf/trafficserver.git
commit afcb78de81cd9c2db48edce1f535dec775196de4 Author: Zeyuan Yu <[email protected]> AuthorDate: Wed Feb 7 18:47:29 2018 +0000 Added logcode and stats --- proxy/hdrs/HTTP.h | 4 +++- proxy/http/HttpConfig.cc | 18 ++++++++++++++++++ proxy/http/HttpConfig.h | 6 ++++++ proxy/http/HttpSM.cc | 22 ++++++++++++++++++---- proxy/http/HttpTransact.cc | 10 ++++++++++ proxy/logging/Log.cc | 23 ++++++++++++++++++++++- proxy/logstats.cc | 16 ++++++++++++++++ proxy/tests/logstats.json | 4 ++++ proxy/tests/logstats.summary | 2 ++ 9 files changed, 99 insertions(+), 6 deletions(-) diff --git a/proxy/hdrs/HTTP.h b/proxy/hdrs/HTTP.h index bc18c02..ba221d6 100644 --- a/proxy/hdrs/HTTP.h +++ b/proxy/hdrs/HTTP.h @@ -142,7 +142,9 @@ enum SquidLogCode { SQUID_LOG_ERR_POST_ENTITY_TOO_LARGE = 'L', SQUID_LOG_ERR_NO_CLIENTS_BIG_OBJ = 'r', SQUID_LOG_ERR_READ_ERROR = 's', - SQUID_LOG_ERR_CLIENT_ABORT = 't', + SQUID_LOG_ERR_CLIENT_ABORT = 't', // Client side abort logging + SQUID_LOG_ERR_CLIENT_READ_TIMEOUT = 'J', // Client side abort logging + SQUID_LOG_ERR_CLIENT_READ_ERROR = 'K', // Client side abort logging SQUID_LOG_ERR_CONNECT_FAIL = 'u', SQUID_LOG_ERR_INVALID_REQ = 'v', SQUID_LOG_ERR_UNSUP_REQ = 'w', diff --git a/proxy/http/HttpConfig.cc b/proxy/http/HttpConfig.cc index c58ccce..e9932b5 100644 --- a/proxy/http/HttpConfig.cc +++ b/proxy/http/HttpConfig.cc @@ -603,6 +603,24 @@ register_stat_callbacks() RecRegisterRawStat(http_rsb, RECT_PROCESS, "proxy.process.http.err_client_abort_origin_server_bytes_stat", RECD_INT, RECP_PERSISTENT, (int)http_err_client_abort_origin_server_bytes_stat, RecRawStatSyncSum); + RecRegisterRawStat(http_rsb, RECT_PROCESS, "proxy.process.http.err_client_read_timeout_count_stat", RECD_COUNTER, RECP_PERSISTENT, + (int)http_err_client_read_timeout_count_stat, RecRawStatSyncCount); + + RecRegisterRawStat(http_rsb, RECT_PROCESS, "proxy.process.http.err_client_read_timeout_user_agent_bytes_stat", RECD_INT, RECP_PERSISTENT, + (int)http_err_client_read_timeout_user_agent_bytes_stat, RecRawStatSyncSum); + + RecRegisterRawStat(http_rsb, RECT_PROCESS, "proxy.process.http.err_client_read_timeout_origin_server_bytes_stat", RECD_INT, + RECP_PERSISTENT, (int)http_err_client_read_timeout_origin_server_bytes_stat, RecRawStatSyncSum); +// + RecRegisterRawStat(http_rsb, RECT_PROCESS, "proxy.process.http.err_client_read_error_count_stat", RECD_COUNTER, RECP_PERSISTENT, + (int)http_err_client_read_error_count_stat, RecRawStatSyncCount); + + RecRegisterRawStat(http_rsb, RECT_PROCESS, "proxy.process.http.err_client_read_error_user_agent_bytes_stat", RECD_INT, RECP_PERSISTENT, + (int)http_err_client_read_error_user_agent_bytes_stat, RecRawStatSyncSum); + + RecRegisterRawStat(http_rsb, RECT_PROCESS, "proxy.process.http.err_client_read_error_origin_server_bytes_stat", RECD_INT, + RECP_PERSISTENT, (int)http_err_client_read_error_origin_server_bytes_stat, RecRawStatSyncSum); + RecRegisterRawStat(http_rsb, RECT_PROCESS, "proxy.process.http.err_connect_fail_count_stat", RECD_COUNTER, RECP_PERSISTENT, (int)http_err_connect_fail_count_stat, RecRawStatSyncCount); diff --git a/proxy/http/HttpConfig.h b/proxy/http/HttpConfig.h index b4e1d81..10653c3 100644 --- a/proxy/http/HttpConfig.h +++ b/proxy/http/HttpConfig.h @@ -211,6 +211,12 @@ enum { http_err_client_abort_count_stat, http_err_client_abort_user_agent_bytes_stat, http_err_client_abort_origin_server_bytes_stat, + http_err_client_read_timeout_count_stat, + http_err_client_read_timeout_user_agent_bytes_stat, + http_err_client_read_timeout_origin_server_bytes_stat, + http_err_client_read_error_count_stat, + http_err_client_read_error_user_agent_bytes_stat, + http_err_client_read_error_origin_server_bytes_stat, http_err_connect_fail_count_stat, http_err_connect_fail_user_agent_bytes_stat, http_err_connect_fail_origin_server_bytes_stat, diff --git a/proxy/http/HttpSM.cc b/proxy/http/HttpSM.cc index 6ffbdf5..fdf0065 100644 --- a/proxy/http/HttpSM.cc +++ b/proxy/http/HttpSM.cc @@ -615,7 +615,7 @@ HttpSM::state_read_client_request_header(int event, void *data) // bail on the state machine vc_table.cleanup_entry(ua_entry); ua_entry = nullptr; - t_state.client_info.abort = HttpTransact::ABORTED; + set_ua_abort(HttpTransact::ABORTED, event); terminate_sm = true; return 0; } @@ -1004,7 +1004,7 @@ HttpSM::state_read_push_response_header(int event, void *data) case VC_EVENT_INACTIVITY_TIMEOUT: case VC_EVENT_ACTIVE_TIMEOUT: // The user agent is hosed. Send an error - t_state.client_info.abort = HttpTransact::ABORTED; + set_ua_abort(HttpTransact::ABORTED, event); call_transact_and_set_next_state(HttpTransact::HandleBadPushRespHdr); return 0; } @@ -3299,7 +3299,7 @@ HttpSM::tunnel_handler_ua_push(int event, HttpTunnelProducer *p) case VC_EVENT_ERROR: case VC_EVENT_EOS: // Transfer terminated. Bail on the cache write. - t_state.client_info.abort = HttpTransact::ABORTED; + set_ua_abort(HttpTransact::ABORTED, event); p->vc->do_io_close(EHTTP_ERROR); p->read_vio = nullptr; tunnel.chain_abort_all(p); @@ -5152,7 +5152,21 @@ HttpSM::set_ua_abort(HttpTransact::AbortState_t ua_abort, int event) switch (ua_abort) { case HttpTransact::ABORTED: case HttpTransact::MAYBE_ABORTED: - t_state.squid_codes.log_code = SQUID_LOG_ERR_CLIENT_ABORT; + // More detailed client side abort logging based on event + switch (event) { + case VC_EVENT_ACTIVE_TIMEOUT: + case VC_EVENT_INACTIVITY_TIMEOUT: + t_state.squid_codes.log_code = SQUID_LOG_ERR_CLIENT_READ_TIMEOUT; + break; + case VC_EVENT_ERROR: + t_state.squid_codes.log_code = SQUID_LOG_ERR_CLIENT_READ_ERROR; + break; + case VC_EVENT_EOS: + // Fall-through + default: + t_state.squid_codes.log_code = SQUID_LOG_ERR_CLIENT_ABORT; + break; + } break; default: // Handled here: diff --git a/proxy/http/HttpTransact.cc b/proxy/http/HttpTransact.cc index 6ad5767..6f4aaef 100644 --- a/proxy/http/HttpTransact.cc +++ b/proxy/http/HttpTransact.cc @@ -8518,6 +8518,16 @@ HttpTransact::update_size_and_time_stats(State *s, ink_hrtime total_time, ink_hr HTTP_SUM_DYN_STAT(http_err_client_abort_user_agent_bytes_stat, user_agent_bytes); HTTP_SUM_DYN_STAT(http_err_client_abort_origin_server_bytes_stat, origin_server_bytes); break; + case SQUID_LOG_ERR_CLIENT_READ_TIMEOUT: + HTTP_INCREMENT_DYN_STAT(http_err_client_read_timeout_count_stat); + HTTP_SUM_DYN_STAT(http_err_client_read_timeout_user_agent_bytes_stat, user_agent_bytes); + HTTP_SUM_DYN_STAT(http_err_client_read_timeout_origin_server_bytes_stat, origin_server_bytes); + break; + case SQUID_LOG_ERR_CLIENT_READ_ERROR: + HTTP_INCREMENT_DYN_STAT(http_err_client_read_error_count_stat); + HTTP_SUM_DYN_STAT(http_err_client_read_error_user_agent_bytes_stat, user_agent_bytes); + HTTP_SUM_DYN_STAT(http_err_client_read_error_origin_server_bytes_stat, origin_server_bytes); + break; case SQUID_LOG_ERR_CONNECT_FAIL: HTTP_INCREMENT_DYN_STAT(http_err_connect_fail_count_stat); HTTP_SUM_DYN_STAT(http_err_connect_fail_user_agent_bytes_stat, user_agent_bytes); diff --git a/proxy/logging/Log.cc b/proxy/logging/Log.cc index 0a2fe4d..8997e86 100644 --- a/proxy/logging/Log.cc +++ b/proxy/logging/Log.cc @@ -588,13 +588,34 @@ Log::init_fields() "UDP_INVALID", SQUID_LOG_UDP_RELOADING, "UDP_RELOADING", SQUID_LOG_UDP_FUTURE_1, "UDP_FUTURE_1", SQUID_LOG_UDP_FUTURE_2, "UDP_FUTURE_2", SQUID_LOG_ERR_READ_TIMEOUT, "ERR_READ_TIMEOUT", SQUID_LOG_ERR_LIFETIME_EXP, "ERR_LIFETIME_EXP", SQUID_LOG_ERR_POST_ENTITY_TOO_LARGE, "ERR_POST_ENTITY_TOO_LARGE", SQUID_LOG_ERR_NO_CLIENTS_BIG_OBJ, "ERR_NO_CLIENTS_BIG_OBJ", - SQUID_LOG_ERR_READ_ERROR, "ERR_READ_ERROR", SQUID_LOG_ERR_CLIENT_ABORT, "ERR_CLIENT_ABORT", SQUID_LOG_ERR_CONNECT_FAIL, + SQUID_LOG_ERR_READ_ERROR, "ERR_READ_ERROR", SQUID_LOG_ERR_CLIENT_ABORT, "ERR_CLIENT_ABORT_TEST", SQUID_LOG_ERR_CONNECT_FAIL, "ERR_CONNECT_FAIL", SQUID_LOG_ERR_INVALID_REQ, "ERR_INVALID_REQ", SQUID_LOG_ERR_UNSUP_REQ, "ERR_UNSUP_REQ", SQUID_LOG_ERR_INVALID_URL, "ERR_INVALID_URL", SQUID_LOG_ERR_NO_FDS, "ERR_NO_FDS", SQUID_LOG_ERR_DNS_FAIL, "ERR_DNS_FAIL", SQUID_LOG_ERR_NOT_IMPLEMENTED, "ERR_NOT_IMPLEMENTED", SQUID_LOG_ERR_CANNOT_FETCH, "ERR_CANNOT_FETCH", SQUID_LOG_ERR_NO_RELAY, "ERR_NO_RELAY", SQUID_LOG_ERR_DISK_IO, "ERR_DISK_IO", SQUID_LOG_ERR_ZERO_SIZE_OBJECT, "ERR_ZERO_SIZE_OBJECT", SQUID_LOG_ERR_PROXY_DENIED, "ERR_PROXY_DENIED", SQUID_LOG_ERR_WEBFETCH_DETECTED, "ERR_WEBFETCH_DETECTED", SQUID_LOG_ERR_FUTURE_1, "ERR_FUTURE_1", SQUID_LOG_ERR_UNKNOWN, "ERR_UNKNOWN"); + // cache_code_map->init( + // 52, SQUID_LOG_EMPTY, "UNDEFINED", SQUID_LOG_TCP_HIT, "TCP_HIT", SQUID_LOG_TCP_DISK_HIT, "TCP_DISK_HIT", SQUID_LOG_TCP_MEM_HIT, + // "TCP_MEM_HIT", SQUID_LOG_TCP_MISS, "TCP_MISS", SQUID_LOG_TCP_EXPIRED_MISS, "TCP_EXPIRED_MISS", SQUID_LOG_TCP_REFRESH_HIT, + // "TCP_REFRESH_HIT", SQUID_LOG_TCP_REF_FAIL_HIT, "TCP_REFRESH_FAIL_HIT", SQUID_LOG_TCP_REFRESH_MISS, "TCP_REFRESH_MISS", + // SQUID_LOG_TCP_CLIENT_REFRESH, "TCP_CLIENT_REFRESH_MISS", SQUID_LOG_TCP_IMS_HIT, "TCP_IMS_HIT", SQUID_LOG_TCP_IMS_MISS, + // "TCP_IMS_MISS", SQUID_LOG_TCP_SWAPFAIL, "TCP_SWAPFAIL_MISS", SQUID_LOG_TCP_DENIED, "TCP_DENIED", SQUID_LOG_TCP_WEBFETCH_MISS, + // "TCP_WEBFETCH_MISS", SQUID_LOG_TCP_FUTURE_2, "TCP_FUTURE_2", SQUID_LOG_TCP_HIT_REDIRECT, "TCP_HIT_REDIRECT", + // SQUID_LOG_TCP_MISS_REDIRECT, "TCP_MISS_REDIRECT", SQUID_LOG_TCP_HIT_X_REDIRECT, "TCP_HIT_X_REDIRECT", + // SQUID_LOG_TCP_MISS_X_REDIRECT, "TCP_MISS_X_REDIRECT", SQUID_LOG_UDP_HIT, "UDP_HIT", SQUID_LOG_UDP_WEAK_HIT, "UDP_WEAK_HIT", + // SQUID_LOG_UDP_HIT_OBJ, "UDP_HIT_OBJ", SQUID_LOG_UDP_MISS, "UDP_MISS", SQUID_LOG_UDP_DENIED, "UDP_DENIED", SQUID_LOG_UDP_INVALID, + // "UDP_INVALID", SQUID_LOG_UDP_RELOADING, "UDP_RELOADING", SQUID_LOG_UDP_FUTURE_1, "UDP_FUTURE_1", SQUID_LOG_UDP_FUTURE_2, + // "UDP_FUTURE_2", SQUID_LOG_ERR_READ_TIMEOUT, "ERR_READ_TIMEOUT", SQUID_LOG_ERR_LIFETIME_EXP, "ERR_LIFETIME_EXP", + // SQUID_LOG_ERR_POST_ENTITY_TOO_LARGE, "ERR_POST_ENTITY_TOO_LARGE", SQUID_LOG_ERR_NO_CLIENTS_BIG_OBJ, "ERR_NO_CLIENTS_BIG_OBJ", + // SQUID_LOG_ERR_READ_ERROR, "ERR_READ_ERROR", SQUID_LOG_ERR_CLIENT_ABORT, "ERR_CLIENT_ABORT_TEST", SQUID_LOG_ERR_CLIENT_READ_TIMEOUT, + // "ERR_CLIENT_READ_TIMEOUT", SQUID_LOG_ERR_CLIENT_READ_ERROR, "ERR_CLIENT_READ_ERROR", SQUID_LOG_ERR_CONNECT_FAIL, + // "ERR_CONNECT_FAIL", SQUID_LOG_ERR_INVALID_REQ, "ERR_INVALID_REQ", SQUID_LOG_ERR_UNSUP_REQ, "ERR_UNSUP_REQ", + // SQUID_LOG_ERR_INVALID_URL, "ERR_INVALID_URL", SQUID_LOG_ERR_NO_FDS, "ERR_NO_FDS", SQUID_LOG_ERR_DNS_FAIL, "ERR_DNS_FAIL", + // SQUID_LOG_ERR_NOT_IMPLEMENTED, "ERR_NOT_IMPLEMENTED", SQUID_LOG_ERR_CANNOT_FETCH, "ERR_CANNOT_FETCH", SQUID_LOG_ERR_NO_RELAY, + // "ERR_NO_RELAY", SQUID_LOG_ERR_DISK_IO, "ERR_DISK_IO", SQUID_LOG_ERR_ZERO_SIZE_OBJECT, "ERR_ZERO_SIZE_OBJECT", + // SQUID_LOG_ERR_PROXY_DENIED, "ERR_PROXY_DENIED", SQUID_LOG_ERR_WEBFETCH_DETECTED, "ERR_WEBFETCH_DETECTED", + // SQUID_LOG_ERR_FUTURE_1, "ERR_FUTURE_1", SQUID_LOG_ERR_UNKNOWN, "ERR_UNKNOWN"); Ptr<LogFieldAliasTable> cache_hit_miss_map = make_ptr(new LogFieldAliasTable); cache_hit_miss_map->init(21, SQUID_HIT_RESERVED, "HIT", SQUID_HIT_LEVEL_1, "HIT_RAM", // Also SQUID_HIT_RAM diff --git a/proxy/logstats.cc b/proxy/logstats.cc index 0c1d2ac..ec9d9e6 100644 --- a/proxy/logstats.cc +++ b/proxy/logstats.cc @@ -157,6 +157,8 @@ struct OriginStats { } misses; struct { StatsCounter client_abort; + StatsCounter client_read_timeout; + StatsCounter client_read_error; StatsCounter connect_fail; StatsCounter invalid_req; StatsCounter unknown; @@ -437,6 +439,8 @@ public: ++(l->misses); break; case SQUID_LOG_ERR_CLIENT_ABORT: + case SQUID_LOG_ERR_CLIENT_READ_TIMEOUT: + case SQUID_LOG_ERR_CLIENT_READ_ERROR: case SQUID_LOG_ERR_CONNECT_FAIL: case SQUID_LOG_ERR_INVALID_REQ: case SQUID_LOG_ERR_UNKNOWN: @@ -510,6 +514,8 @@ public: l->misses = 1; break; case SQUID_LOG_ERR_CLIENT_ABORT: + case SQUID_LOG_ERR_CLIENT_READ_TIMEOUT: + case SQUID_LOG_ERR_CLIENT_READ_ERROR: case SQUID_LOG_ERR_CONNECT_FAIL: case SQUID_LOG_ERR_INVALID_REQ: case SQUID_LOG_ERR_UNKNOWN: @@ -933,6 +939,14 @@ update_results_elapsed(OriginStats *stat, int result, int elapsed, int size) update_counter(stat->results.errors.client_abort, size); update_counter(stat->results.errors.total, size); break; + case SQUID_LOG_ERR_CLIENT_READ_TIMEOUT: + update_counter(stat->results.errors.client_read_timeout, size); + update_counter(stat->results.errors.total, size); + break; + case SQUID_LOG_ERR_CLIENT_READ_ERROR: + update_counter(stat->results.errors.client_read_error, size); + update_counter(stat->results.errors.total, size); + break; case SQUID_LOG_ERR_CONNECT_FAIL: update_counter(stat->results.errors.connect_fail, size); update_counter(stat->results.errors.total, size); @@ -2024,6 +2038,8 @@ print_detail_stats(const OriginStats *stat, bool json, bool concise) } format_line(json ? "error.client_abort" : "Client aborted", stat->results.errors.client_abort, stat->total, json, concise); + format_line(json ? "error.client_read_timeout": "Client read timeout", stat->results.errors.client_read_timeout, stat->total, json, concise); + format_line(json ? "error.client_read_error": "Client read error", stat->results.errors.client_read_error, stat->total, json, concise); format_line(json ? "error.connect_failed" : "Connect failed", stat->results.errors.connect_fail, stat->total, json, concise); format_line(json ? "error.invalid_request" : "Invalid request", stat->results.errors.invalid_req, stat->total, json, concise); format_line(json ? "error.unknown" : "Unknown error(99)", stat->results.errors.unknown, stat->total, json, concise); diff --git a/proxy/tests/logstats.json b/proxy/tests/logstats.json index d9609e8..819a821 100644 --- a/proxy/tests/logstats.json +++ b/proxy/tests/logstats.json @@ -11,6 +11,8 @@ "miss.other" : { "req": "0", "req_pct": "0.00", "bytes": "0", "bytes_pct": "0.00" }, "miss.total" : { "req": "66", "req_pct": "98.51", "bytes": "6601222", "bytes_pct": "100.00" }, "error.client_abort" : { "req": "1", "req_pct": "1.49", "bytes": "0", "bytes_pct": "0.00" }, + "error.client_read_timeout" : { "req": "0", "req_pct": "0.00", "bytes": "0", "bytes_pct": "0.00" }, + "error.client_read_error" : { "req": "0", "req_pct": "0.00", "bytes": "0", "bytes_pct": "0.00" }, "error.connect_failed" : { "req": "0", "req_pct": "0.00", "bytes": "0", "bytes_pct": "0.00" }, "error.invalid_request" : { "req": "0", "req_pct": "0.00", "bytes": "0", "bytes_pct": "0.00" }, "error.unknown" : { "req": "0", "req_pct": "0.00", "bytes": "0", "bytes_pct": "0.00" }, @@ -136,6 +138,8 @@ "miss.other" : { "req": "0", "req_pct": "0.00", "bytes": "0", "bytes_pct": "0.00" }, "miss.total" : { "req": "66", "req_pct": "98.51", "bytes": "6601222", "bytes_pct": "100.00" }, "error.client_abort" : { "req": "1", "req_pct": "1.49", "bytes": "0", "bytes_pct": "0.00" }, + "error.client_read_timeout" : { "req": "0", "req_pct": "0.00", "bytes": "0", "bytes_pct": "0.00" }, + "error.client_read_error" : { "req": "0", "req_pct": "0.00", "bytes": "0", "bytes_pct": "0.00" }, "error.connect_failed" : { "req": "0", "req_pct": "0.00", "bytes": "0", "bytes_pct": "0.00" }, "error.invalid_request" : { "req": "0", "req_pct": "0.00", "bytes": "0", "bytes_pct": "0.00" }, "error.unknown" : { "req": "0", "req_pct": "0.00", "bytes": "0", "bytes_pct": "0.00" }, diff --git a/proxy/tests/logstats.summary b/proxy/tests/logstats.summary index 34a4560..13bcb8c 100644 --- a/proxy/tests/logstats.summary +++ b/proxy/tests/logstats.summary @@ -16,6 +16,8 @@ Cache miss other 0 0.00% 0.00KB 0.00% Cache miss total 66 98.51% 6.30MB 100.00% Client aborted 1 1.49% 0.00KB 0.00% +Client read timeout 0 0.00% 0.00KB 0.00% +Client read error 0 0.00% 0.00KB 0.00% Connect failed 0 0.00% 0.00KB 0.00% Invalid request 0 0.00% 0.00KB 0.00% Unknown error(99) 0 0.00% 0.00KB 0.00% -- To stop receiving notification emails like this one, please contact [email protected].
