diff --git a/Variables.CMakeFile b/Variables.CMakeFile index 3ab2bb1d0c..cbfc96fd9b 100644 --- a/Variables.CMakeFile +++ b/Variables.CMakeFile @@ -128,6 +128,7 @@ dir2macro(OIO_SERVER_FD_MAX_PASSIVE) dir2macro(OIO_SERVER_LOG_OUTGOING) dir2macro(OIO_SERVER_MALLOC_TRIM_SIZE_ONDEMAND) dir2macro(OIO_SERVER_MALLOC_TRIM_SIZE_PERIODIC) +dir2macro(OIO_SERVER_PERFDATA_ENABLED) dir2macro(OIO_SERVER_PERIODIC_DECACHE_MAX_BASES) dir2macro(OIO_SERVER_PERIODIC_DECACHE_MAX_DELAY) dir2macro(OIO_SERVER_PERIODIC_DECACHE_PERIOD) diff --git a/Variables.md b/Variables.md index ba95391961..ba5a6a7153 100644 --- a/Variables.md +++ b/Variables.md @@ -1103,6 +1103,14 @@ Used by `gcc` * cmake directive: *OIO_SERVER_MALLOC_TRIM_SIZE_PERIODIC* * range: 0 -> 2147483648 +### server.perfdata.enabled + +> Enable server-side performance data collection. + + * default: **FALSE** + * type: gboolean + * cmake directive: *OIO_SERVER_PERFDATA_ENABLED* + ### server.periodic_decache.max_bases > How many bases may be decached each time the background task performs its Dance of Death diff --git a/conf.json b/conf.json index d9f36a7cb9..28bd61664b 100644 --- a/conf.json +++ b/conf.json @@ -312,6 +312,11 @@ "def": false, "descr": "" }, + { "type": "bool", "name": "server_perfdata_enabled", + "key": "server.perfdata.enabled", + "def": false, + "descr": "Enable server-side performance data collection."}, + { "type": "bool", "name": "oio_socket_linger_onoff", "key": "socket.linger.enabled", "def": false, @@ -813,6 +818,7 @@ "descr": "How long a request might take to run on the server side. This value is used to compute a deadline for several waitings (DB cache, manager of elections, etc). Common to all sqliterepo-based services, it might be overriden.", "def": "300s", "min": "1ms", "max": "1h", "aliases": ["server.request.max_delay_start"] } + ] }, "proxy": { diff --git a/core/ext.c b/core/ext.c index ad34e2ad0b..4b2cb52282 100644 --- a/core/ext.c +++ b/core/ext.c @@ -1,6 +1,6 @@ /* OpenIO SDS core library -Copyright (C) 2015-2017 OpenIO SAS, as part of OpenIO SDS +Copyright (C) 2015-2020 OpenIO SAS, as part of OpenIO SDS This library is free software; you can redistribute it and/or modify it under the terms of the GNU Lesser General Public @@ -181,6 +181,7 @@ struct oio_ext_local_s { gchar *force_versioning; guint8 simulate_versioning; gchar reqid[LIMIT_LENGTH_REQID]; + GHashTable *perfdata; }; static void _local_free(gpointer p) { @@ -199,6 +200,10 @@ static void _local_free(gpointer p) { g_free(l->force_versioning); l->force_versioning = NULL; } + if (l->perfdata) { + g_hash_table_destroy(l->perfdata); + l->perfdata = NULL; + } g_free (l); } @@ -352,6 +357,32 @@ void oio_ext_set_simulate_versioning(const gboolean simulate_versioning) { l->simulate_versioning = BOOL(simulate_versioning); } +GHashTable *oio_ext_get_perfdata(void) { + struct oio_ext_local_s *l = _local_ensure(); + return l->perfdata; +} + +GHashTable *oio_ext_enable_perfdata(gboolean enabled) { + struct oio_ext_local_s *l = _local_ensure(); + if (enabled && !l->perfdata) { + l->perfdata = g_hash_table_new_full( + g_str_hash, g_str_equal, g_free, NULL); + } else if (!enabled && l->perfdata) { + g_hash_table_destroy(l->perfdata); + l->perfdata = NULL; + } + return l->perfdata; +} + +void oio_ext_add_perfdata(const gchar *key, gint64 value) { + struct oio_ext_local_s *l = _local_ensure(); + if (l->perfdata) { + gint64 old = GPOINTER_TO_INT(g_hash_table_lookup(l->perfdata, key)); + g_hash_table_insert(l->perfdata, + g_strdup(key), GINT_TO_POINTER(old + value)); + } +} + /* -------------------------------------------------------------------------- */ # ifdef HAVE_BACKTRACE diff --git a/core/oioext.h b/core/oioext.h index 5a8603660e..b2bae1379a 100644 --- a/core/oioext.h +++ b/core/oioext.h @@ -1,6 +1,6 @@ /* OpenIO SDS core library -Copyright (C) 2015-2017 OpenIO SAS, as part of OpenIO SDS +Copyright (C) 2015-2020 OpenIO SAS, as part of OpenIO SDS This library is free software; you can redistribute it and/or modify it under the terms of the GNU Lesser General Public @@ -125,6 +125,17 @@ gboolean oio_ext_has_simulate_versioning(void); void oio_ext_set_simulate_versioning(const gboolean simulate_versioning); +/** Enable or disable the performance data collection. */ +GHashTable *oio_ext_enable_perfdata(gboolean enabled); + +/** Get the performance data hash table (will be NULL when disabled) */ +GHashTable *oio_ext_get_perfdata(void); + +/** Add one metric in the performance data hash table. + * Does not take ownership of the key. + * When called several times with the same key, add values. */ +void oio_ext_add_perfdata(const gchar *key, gint64 value); + gint64 oio_ext_real_time (void); gint64 oio_ext_monotonic_time (void); diff --git a/metautils/lib/comm_message.c b/metautils/lib/comm_message.c index cd73acfc01..69fdc07519 100644 --- a/metautils/lib/comm_message.c +++ b/metautils/lib/comm_message.c @@ -1,7 +1,7 @@ /* OpenIO SDS metautils Copyright (C) 2014 Worldline, as part of Redcurrant -Copyright (C) 2015-2017 OpenIO SAS, as part of OpenIO SDS +Copyright (C) 2015-2020 OpenIO SAS, as part of OpenIO SDS This library is free software; you can redistribute it and/or modify it under the terms of the GNU Lesser General Public @@ -151,6 +151,9 @@ message_marshall_gba(MESSAGE m, GError **err) if (oio_ext_has_simulate_versioning()) metautils_message_add_field_strint(m, NAME_MSGKEY_SIM_VER, 1); + if (oio_ext_get_perfdata()) + metautils_message_add_field_strint(m, NAME_MSGKEY_PERFDATA, 1); + const gchar *user_agent = oio_ext_get_user_agent(); if (user_agent != NULL) metautils_message_add_field_str( diff --git a/metautils/lib/metautils_macros.h b/metautils/lib/metautils_macros.h index aebde9062f..0ed951c029 100644 --- a/metautils/lib/metautils_macros.h +++ b/metautils/lib/metautils_macros.h @@ -1,7 +1,7 @@ /* OpenIO SDS metautils Copyright (C) 2014 Worldline, as part of Redcurrant -Copyright (C) 2015-2019 OpenIO SAS, as part of OpenIO SDS +Copyright (C) 2015-2020 OpenIO SAS, as part of OpenIO SDS This library is free software; you can redistribute it and/or modify it under the terms of the GNU Lesser General Public @@ -85,6 +85,7 @@ License along with this library. #define NAME_MSGKEY_NOTIN "!IN" #define NAME_MSGKEY_OLD "OLD" #define NAME_MSGKEY_OVERWRITE "OVERWRITE" +#define NAME_MSGKEY_PERFDATA "PERF" #define NAME_MSGKEY_PREFIX "PREFIX" #define NAME_MSGKEY_QUERY "Q" #define NAME_MSGKEY_RECOMPUTE "RECOMPUTE" diff --git a/proxy/m2_actions.c b/proxy/m2_actions.c index f860ef0c43..1219c51e31 100644 --- a/proxy/m2_actions.c +++ b/proxy/m2_actions.c @@ -1,7 +1,7 @@ /* OpenIO SDS proxy Copyright (C) 2014 Worldline, as part of Redcurrant -Copyright (C) 2015-2019 OpenIO SAS, as part of OpenIO SDS +Copyright (C) 2015-2020 OpenIO SAS, as part of OpenIO SDS This program is free software: you can redistribute it and/or modify it under the terms of the GNU Affero General Public License as @@ -53,6 +53,10 @@ _resolve_meta2(struct req_args_s *args, enum proxy_preference_e how, out_list = (GSList **) out; *out_list = NULL; } + /* Check if the client application wants performance data. */ + gboolean req_perfdata_enabled = + g_tree_lookup(args->rq->tree_headers, PROXYD_HEADER_PERFDATA) != NULL; + oio_ext_enable_perfdata(req_perfdata_enabled); GError *err = gridd_request_replicated_with_retry(args, &ctx, pack); @@ -73,13 +77,14 @@ _resolve_meta2(struct req_args_s *args, enum proxy_preference_e how, } } } - if (g_tree_lookup(args->rq->tree_headers, PROXYD_HEADER_PERFDATA)) { + if (req_perfdata_enabled) { gchar *perfdata = g_strdup_printf( "resolve=%"G_GINT64_FORMAT",meta2=%"G_GINT64_FORMAT, ctx.resolve_duration, ctx.request_duration); args->rp->add_header(PROXYD_HEADER_PERFDATA, perfdata); } + oio_ext_enable_perfdata(FALSE); client_clean (&ctx); return err; } diff --git a/server/transport_gridd.c b/server/transport_gridd.c index 6544aa5ea1..de113d2c43 100644 --- a/server/transport_gridd.c +++ b/server/transport_gridd.c @@ -1,7 +1,7 @@ /* OpenIO SDS server Copyright (C) 2014 Worldline, as part of Redcurrant -Copyright (C) 2015-2019 OpenIO SAS, as part of OpenIO SDS +Copyright (C) 2015-2020 OpenIO SAS, as part of OpenIO SDS This library is free software; you can redistribute it and/or modify it under the terms of the GNU Lesser General Public @@ -229,6 +229,15 @@ network_client_log_access(struct log_item_s *item) /* arbitrary */ g_string_append_printf(gstr, " t=%"G_GINT64_FORMAT, diff_handler); + GHashTable *perfdata = oio_ext_get_perfdata(); + if (perfdata) { + void __log_perfdata(gpointer key, gpointer val, gpointer udata UNUSED) + { + g_string_append_printf(gstr, " %s=%"G_GINT64_FORMAT, + (char*)key, (gint64)GPOINTER_TO_INT(val)); + } + g_hash_table_foreach(perfdata, __log_perfdata, NULL); + } if (r->subject) { g_string_append_c (gstr, ' '); g_string_append(gstr, ensure(r->subject)); @@ -514,9 +523,16 @@ _notify_request(struct req_ctx_s *ctx, GQuark gq_count, GQuark gq_time) static gsize _reply_message(struct network_client_s *clt, MESSAGE reply) { + gint64 start = oio_ext_monotonic_time(); GByteArray *encoded = message_marshall_gba_and_clean(reply); + gint64 encode = oio_ext_monotonic_time(); gsize encoded_size = encoded->len; network_client_send_slab(clt, data_slab_make_gba(encoded)); + gint64 send = oio_ext_monotonic_time(); + if (server_perfdata_enabled) { + oio_ext_add_perfdata("resp_encode", encode - start); + oio_ext_add_perfdata("resp_send", send - encode); + } return encoded_size; } @@ -587,8 +603,10 @@ _client_call_handler(struct req_ctx_s *req_ctx) GHashTableIter iter; gpointer n, v; g_hash_table_iter_init(&iter, headers); - while (g_hash_table_iter_next(&iter, &n, &v)) - metautils_message_add_field(answer, (gchar*)n, ((GByteArray*)v)->data, ((GByteArray*)v)->len); + while (g_hash_table_iter_next(&iter, &n, &v)) { + metautils_message_add_field(answer, (gchar*)n, + ((GByteArray*)v)->data, ((GByteArray*)v)->len); + } } /* encode and send */ @@ -661,6 +679,11 @@ _client_call_handler(struct req_ctx_s *req_ctx) ctx.deadline = MIN(ctx.deadline, req_deadline); } } + gint64 req_perfdata_enabled = FALSE; + if (metautils_message_extract_string_noerror(req_ctx->request, + NAME_MSGKEY_PERFDATA, tostr, sizeof(tostr))) { + oio_str_is_number(tostr, &req_perfdata_enabled); + } /* Ugly quirk: it is currently too expansive to alter all the calls to * the meta2 backend, especially right now while we are writing this @@ -668,6 +691,10 @@ _client_call_handler(struct req_ctx_s *req_ctx) * context with all the common open args, in 4.x, while there is one in * the 'master' branch. */ oio_ext_set_deadline(ctx.deadline); + if (req_perfdata_enabled || server_perfdata_enabled) { + oio_ext_enable_perfdata(TRUE); + oio_ext_add_perfdata("req_decode", now - req_ctx->tv_start); + } gboolean rc = FALSE; if (req_ctx->tv_start < OLDEST(now, meta_queue_max_delay)) { @@ -704,6 +731,7 @@ _client_call_handler(struct req_ctx_s *req_ctx) EXTRA_ASSERT(body == NULL); if (headers) g_hash_table_destroy(headers); + oio_ext_enable_perfdata(FALSE); return rc; } diff --git a/sqliterepo/cache.c b/sqliterepo/cache.c index 75d24be5e1..263e9ca6a3 100644 --- a/sqliterepo/cache.c +++ b/sqliterepo/cache.c @@ -745,8 +745,10 @@ sqlx_cache_open_and_lock_base(sqlx_cache_t *cache, const hashstr_t *hname, if (base) { gint64 now = oio_ext_monotonic_time(); time_t now_secs = now / G_TIME_SPAN_SECOND; + gint64 wait_time = now - start; grid_single_rrd_add(base->open_attempts, now_secs, 1); - grid_single_rrd_add(base->open_wait_time, now_secs, now - start); + grid_single_rrd_add(base->open_wait_time, now_secs, wait_time); + oio_ext_add_perfdata("db_wait", wait_time); if (!err) { sqlx_base_debug(__FUNCTION__, base); @@ -825,6 +827,7 @@ sqlx_cache_unlock_and_close_base(sqlx_cache_t *cache, gint bd, guint32 flags) if (base && !err) { sqlx_base_debug(__FUNCTION__, base); + oio_ext_add_perfdata("db_lock", lock_time); if (lock_time > _cache_timeout_open * 3 / 4) { GRID_WARN("The current thread held a lock on [%s] for %" G_GINT64_FORMAT"us (sqliterepo.cache.timeout.open=%" diff --git a/sqliterepo/cache.h b/sqliterepo/cache.h index 0ab314a19c..f22f569b89 100644 --- a/sqliterepo/cache.h +++ b/sqliterepo/cache.h @@ -1,7 +1,7 @@ /* OpenIO SDS sqliterepo Copyright (C) 2014 Worldline, as part of Redcurrant -Copyright (C) 2015-2017 OpenIO SAS, as part of OpenIO SDS +Copyright (C) 2015-2020 OpenIO SAS, as part of OpenIO SDS This library is free software; you can redistribute it and/or modify it under the terms of the GNU Lesser General Public diff --git a/sqliterepo/replication.c b/sqliterepo/replication.c index 7ec0060245..d7bbe458b2 100644 --- a/sqliterepo/replication.c +++ b/sqliterepo/replication.c @@ -1,7 +1,7 @@ /* OpenIO SDS sqliterepo Copyright (C) 2014 Worldline, as part of Redcurrant -Copyright (C) 2015-2017 OpenIO SAS, as part of OpenIO SDS +Copyright (C) 2015-2020 OpenIO SAS, as part of OpenIO SDS This library is free software; you can redistribute it and/or modify it under the terms of the GNU Lesser General Public @@ -445,19 +445,20 @@ hook_commit(gpointer d) ctx->any_change = 1; + gint64 start = oio_ext_monotonic_time(); + int rc = 0; if (ctx->huge) { _defer_synchronous_RESYNC(ctx); - return 0; - } - - if (ctx->sequence.list.count <= 0) { + } else if (ctx->sequence.list.count <= 0) { GRID_DEBUG("Empty transaction!"); ctx->any_change = 0; context_flush_rowsets(ctx); - return 0; + } else { + rc = _perform_REPLICATE(ctx); } - - return _perform_REPLICATE(ctx); + gint64 duration = oio_ext_monotonic_time() - start; + oio_ext_add_perfdata("db_commit", duration); + return rc; } static void diff --git a/sqliterepo/repository.c b/sqliterepo/repository.c index 26d2a5f8e2..5e5cf5c94e 100644 --- a/sqliterepo/repository.c +++ b/sqliterepo/repository.c @@ -1,7 +1,7 @@ /* OpenIO SDS sqliterepo Copyright (C) 2014 Worldline, as part of Redcurrant -Copyright (C) 2015-2019 OpenIO SAS, as part of OpenIO SDS +Copyright (C) 2015-2020 OpenIO SAS, as part of OpenIO SDS This library is free software; you can redistribute it and/or modify it under the terms of the GNU Lesser General Public @@ -912,6 +912,7 @@ _open_and_lock_base(struct open_args_s *args, enum election_status_e expected, const gboolean election_configured = election_manager_configured(args->repo->election_manager); + gint64 start = oio_ext_monotonic_time(); if (election_configured && !args->no_refcheck) { gboolean replicated = FALSE; enum election_step_e step = STEP_NONE; @@ -970,6 +971,7 @@ _open_and_lock_base(struct open_args_s *args, enum election_status_e expected, g_free0(url); } + oio_ext_add_perfdata("db_election", oio_ext_monotonic_time() - start); if (!err) err = args->repo->cache