From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from mails.dpdk.org (mails.dpdk.org [217.70.189.124]) by inbox.dpdk.org (Postfix) with ESMTP id 1BA5DA00C4 for ; Wed, 12 Oct 2022 14:31:50 +0200 (CEST) Received: from [217.70.189.124] (localhost [127.0.0.1]) by mails.dpdk.org (Postfix) with ESMTP id 4093F4307E; Wed, 12 Oct 2022 14:31:48 +0200 (CEST) Received: from us-smtp-delivery-124.mimecast.com (us-smtp-delivery-124.mimecast.com [170.10.133.124]) by mails.dpdk.org (Postfix) with ESMTP id 617444307D for ; Wed, 12 Oct 2022 14:31:47 +0200 (CEST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=redhat.com; s=mimecast20190719; t=1665577906; h=from:from:reply-to:subject:subject:date:date:message-id:message-id: to:to:cc:cc:mime-version:mime-version:content-type:content-type: content-transfer-encoding:content-transfer-encoding: in-reply-to:in-reply-to:references:references; bh=e4Tygx5p9+Fa4LrCghuMiU/eNiplWQc4UBewimcT8+Y=; b=JJ7cuYUDakGlwEJI+1QrtaUH+zoAYi3FgS42pkPfnQPMjrEyKS3nReBDqh/2leuGKcI/nZ gTI/FEk3FttcLltkqwM1BnrKDuI5Rd4klKkgZHgO559g16aSsOoPGX/MxoBTvNEgWIePyg aVIoyVCvFCd9G/wwuqbgVUvsUCOJUhw= Received: from mimecast-mx02.redhat.com (mx3-rdu2.redhat.com [66.187.233.73]) by relay.mimecast.com with ESMTP with STARTTLS (version=TLSv1.2, cipher=TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384) id us-mta-256-3J3eh5FjO821ZD-r0u4IhA-1; Wed, 12 Oct 2022 08:31:43 -0400 X-MC-Unique: 3J3eh5FjO821ZD-r0u4IhA-1 Received: from smtp.corp.redhat.com (int-mx06.intmail.prod.int.rdu2.redhat.com [10.11.54.6]) (using TLSv1.2 with cipher AECDH-AES256-SHA (256/256 bits)) (No client certificate requested) by mimecast-mx02.redhat.com (Postfix) with ESMTPS id 538D81C08969; Wed, 12 Oct 2022 12:31:43 +0000 (UTC) Received: from localhost.localdomain (ovpn-193-115.brq.redhat.com [10.40.193.115]) by smtp.corp.redhat.com (Postfix) with ESMTP id 350D92157F56; Wed, 12 Oct 2022 12:31:42 +0000 (UTC) From: David Marchand To: dev@dpdk.org Cc: jerinj@marvell.com, skori@marvell.com, stable@dpdk.org Subject: [PATCH v3 5/9] trace: fix dynamically enabling trace points Date: Wed, 12 Oct 2022 14:31:08 +0200 Message-Id: <20221012123112.2951802-6-david.marchand@redhat.com> In-Reply-To: <20221012123112.2951802-1-david.marchand@redhat.com> References: <20220921120359.2201131-1-david.marchand@redhat.com> <20221012123112.2951802-1-david.marchand@redhat.com> MIME-Version: 1.0 X-Scanned-By: MIMEDefang 3.1 on 10.11.54.6 X-Mimecast-Spam-Score: 0 X-Mimecast-Originator: redhat.com Content-Transfer-Encoding: 8bit Content-Type: text/plain; charset="US-ASCII"; x-default=true X-BeenThere: stable@dpdk.org X-Mailman-Version: 2.1.29 Precedence: list List-Id: patches for DPDK stable branches List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: stable-bounces@dpdk.org Enabling trace points at runtime was not working if no trace point had been enabled first at rte_eal_init() time. The reason was that trace.args reflected the arguments passed to --trace= EAL option. To fix this: - the trace subsystem initialisation is updated: trace directory creation is deferred to when traces are dumped (to avoid creating directories that may not be used), - per lcore memory allocation still relies on rte_trace_is_enabled() but this helper now tracks if any trace point is enabled. The documentation is updated accordingly, - cleanup helpers must always be called in rte_eal_cleanup() since some trace points might have been enabled and disabled in the lifetime of the DPDK application, With this fix, we can update the unit test and check that a trace point callback is invoked when expected. Note: - the 'trace' global variable might be shadowed with the argument passed to the functions dealing with trace point handles. 'tp' has been used for referring to trace_point object. Prefer 't' for referring to handles, Fixes: 84c4fae4628f ("trace: implement operation APIs") Cc: stable@dpdk.org Signed-off-by: David Marchand Acked-by: Sunil Kumar Kori --- Changes since v1: - restored level to INFO for trace directory log message, - moved trace_mkdir() to rte_trace_save, --- app/test/test_trace.c | 20 ++++++++++ app/test/test_trace.h | 2 + doc/guides/prog_guide/trace_lib.rst | 14 +++++-- lib/eal/common/eal_common_trace.c | 53 ++++++++++--------------- lib/eal/common/eal_common_trace_utils.c | 11 ++++- lib/eal/common/eal_trace.h | 3 +- 6 files changed, 65 insertions(+), 38 deletions(-) diff --git a/app/test/test_trace.c b/app/test/test_trace.c index 44ac38a4fa..2660f52f1d 100644 --- a/app/test/test_trace.c +++ b/app/test/test_trace.c @@ -9,6 +9,8 @@ #include "test.h" #include "test_trace.h" +int app_dpdk_test_tp_count; + #ifdef RTE_EXEC_ENV_WINDOWS static int @@ -95,8 +97,15 @@ test_trace_point_regex(void) static int32_t test_trace_point_disable_enable(void) { + int expected; int rc; + /* At tp registration, the associated counter increases once. */ + expected = 1; + TEST_ASSERT_EQUAL(app_dpdk_test_tp_count, expected, + "Expecting %d, but got %d for app_dpdk_test_tp_count", + expected, app_dpdk_test_tp_count); + rc = rte_trace_point_disable(&__app_dpdk_test_tp); if (rc < 0) goto failed; @@ -104,6 +113,12 @@ test_trace_point_disable_enable(void) if (rte_trace_point_is_enabled(&__app_dpdk_test_tp)) goto failed; + /* No emission expected */ + app_dpdk_test_tp("app.dpdk.test.tp"); + TEST_ASSERT_EQUAL(app_dpdk_test_tp_count, expected, + "Expecting %d, but got %d for app_dpdk_test_tp_count", + expected, app_dpdk_test_tp_count); + rc = rte_trace_point_enable(&__app_dpdk_test_tp); if (rc < 0) goto failed; @@ -113,6 +128,11 @@ test_trace_point_disable_enable(void) /* Emit the trace */ app_dpdk_test_tp("app.dpdk.test.tp"); + expected++; + TEST_ASSERT_EQUAL(app_dpdk_test_tp_count, expected, + "Expecting %d, but got %d for app_dpdk_test_tp_count", + expected, app_dpdk_test_tp_count); + return TEST_SUCCESS; failed: diff --git a/app/test/test_trace.h b/app/test/test_trace.h index 413842f60d..4ad44e2bea 100644 --- a/app/test/test_trace.h +++ b/app/test/test_trace.h @@ -3,10 +3,12 @@ */ #include +extern int app_dpdk_test_tp_count; RTE_TRACE_POINT( app_dpdk_test_tp, RTE_TRACE_POINT_ARGS(const char *str), rte_trace_point_emit_string(str); + app_dpdk_test_tp_count++; ) RTE_TRACE_POINT_FP( diff --git a/doc/guides/prog_guide/trace_lib.rst b/doc/guides/prog_guide/trace_lib.rst index fbadf9fde9..9a8f38073d 100644 --- a/doc/guides/prog_guide/trace_lib.rst +++ b/doc/guides/prog_guide/trace_lib.rst @@ -271,10 +271,16 @@ Trace memory The trace memory will be allocated through an internal function ``__rte_trace_mem_per_thread_alloc()``. The trace memory will be allocated per thread to enable lock less trace-emit function. -The memory for the trace memory for DPDK lcores will be allocated on -``rte_eal_init()`` if the trace is enabled through a EAL option. -For non DPDK threads, on the first trace emission, the memory will be -allocated. + +For non lcore threads, the trace memory is allocated on the first trace +emission. + +For lcore threads, if trace points are enabled through a EAL option, the trace +memory is allocated when the threads are known of DPDK +(``rte_eal_init`` for EAL lcores, ``rte_thread_register`` for non-EAL lcores). +Otherwise, when trace points are enabled later in the life of the application, +the behavior is the same as non lcore threads and the trace memory is allocated +on the first trace emission. Trace memory layout ~~~~~~~~~~~~~~~~~~~ diff --git a/lib/eal/common/eal_common_trace.c b/lib/eal/common/eal_common_trace.c index 6b8660c318..6aa11a3b50 100644 --- a/lib/eal/common/eal_common_trace.c +++ b/lib/eal/common/eal_common_trace.c @@ -48,12 +48,6 @@ eal_trace_init(void) goto fail; } - if (!STAILQ_EMPTY(&trace.args)) - trace.status = true; - - if (!rte_trace_is_enabled()) - return 0; - rte_spinlock_init(&trace.lock); /* Is duplicate trace name registered */ @@ -72,13 +66,9 @@ eal_trace_init(void) if (trace_metadata_create() < 0) goto fail; - /* Create trace directory */ - if (trace_mkdir()) - goto free_meta; - /* Save current epoch timestamp for future use */ if (trace_epoch_time_save() < 0) - goto fail; + goto free_meta; /* Apply global configurations */ STAILQ_FOREACH(arg, &trace.args, next) @@ -98,8 +88,6 @@ eal_trace_init(void) void eal_trace_fini(void) { - if (!rte_trace_is_enabled()) - return; trace_mem_free(); trace_metadata_destroy(); eal_trace_args_free(); @@ -108,17 +96,17 @@ eal_trace_fini(void) bool rte_trace_is_enabled(void) { - return trace.status; + return __atomic_load_n(&trace.status, __ATOMIC_ACQUIRE) != 0; } static void -trace_mode_set(rte_trace_point_t *trace, enum rte_trace_mode mode) +trace_mode_set(rte_trace_point_t *t, enum rte_trace_mode mode) { if (mode == RTE_TRACE_MODE_OVERWRITE) - __atomic_and_fetch(trace, ~__RTE_TRACE_FIELD_ENABLE_DISCARD, + __atomic_and_fetch(t, ~__RTE_TRACE_FIELD_ENABLE_DISCARD, __ATOMIC_RELEASE); else - __atomic_or_fetch(trace, __RTE_TRACE_FIELD_ENABLE_DISCARD, + __atomic_or_fetch(t, __RTE_TRACE_FIELD_ENABLE_DISCARD, __ATOMIC_RELEASE); } @@ -146,36 +134,42 @@ trace_point_is_invalid(rte_trace_point_t *t) } bool -rte_trace_point_is_enabled(rte_trace_point_t *trace) +rte_trace_point_is_enabled(rte_trace_point_t *t) { uint64_t val; - if (trace_point_is_invalid(trace)) + if (trace_point_is_invalid(t)) return false; - val = __atomic_load_n(trace, __ATOMIC_ACQUIRE); + val = __atomic_load_n(t, __ATOMIC_ACQUIRE); return (val & __RTE_TRACE_FIELD_ENABLE_MASK) != 0; } int -rte_trace_point_enable(rte_trace_point_t *trace) +rte_trace_point_enable(rte_trace_point_t *t) { - if (trace_point_is_invalid(trace)) + uint64_t prev; + + if (trace_point_is_invalid(t)) return -ERANGE; - __atomic_or_fetch(trace, __RTE_TRACE_FIELD_ENABLE_MASK, - __ATOMIC_RELEASE); + prev = __atomic_fetch_or(t, __RTE_TRACE_FIELD_ENABLE_MASK, __ATOMIC_RELEASE); + if ((prev & __RTE_TRACE_FIELD_ENABLE_MASK) == 0) + __atomic_add_fetch(&trace.status, 1, __ATOMIC_RELEASE); return 0; } int -rte_trace_point_disable(rte_trace_point_t *trace) +rte_trace_point_disable(rte_trace_point_t *t) { - if (trace_point_is_invalid(trace)) + uint64_t prev; + + if (trace_point_is_invalid(t)) return -ERANGE; - __atomic_and_fetch(trace, ~__RTE_TRACE_FIELD_ENABLE_MASK, - __ATOMIC_RELEASE); + prev = __atomic_fetch_and(t, ~__RTE_TRACE_FIELD_ENABLE_MASK, __ATOMIC_RELEASE); + if ((prev & __RTE_TRACE_FIELD_ENABLE_MASK) != 0) + __atomic_sub_fetch(&trace.status, 1, __ATOMIC_RELEASE); return 0; } @@ -417,9 +411,6 @@ trace_mem_free(void) struct trace *trace = trace_obj_get(); uint32_t count; - if (!rte_trace_is_enabled()) - return; - rte_spinlock_lock(&trace->lock); for (count = 0; count < trace->nb_trace_mem_list; count++) { trace_mem_per_thread_free_unlocked(&trace->lcore_meta[count]); diff --git a/lib/eal/common/eal_common_trace_utils.c b/lib/eal/common/eal_common_trace_utils.c index 2b55dbec65..7bf1c05e12 100644 --- a/lib/eal/common/eal_common_trace_utils.c +++ b/lib/eal/common/eal_common_trace_utils.c @@ -314,14 +314,18 @@ trace_dir_default_path_get(char *dir_path) return 0; } -int +static int trace_mkdir(void) { struct trace *trace = trace_obj_get(); char session[TRACE_DIR_STR_LEN]; + static bool already_done; char *dir_path; int rc; + if (already_done) + return 0; + if (!trace->dir_offset) { dir_path = calloc(1, sizeof(trace->dir)); if (dir_path == NULL) { @@ -365,6 +369,7 @@ trace_mkdir(void) } RTE_LOG(INFO, EAL, "Trace dir: %s\n", trace->dir); + already_done = true; return 0; } @@ -434,6 +439,10 @@ rte_trace_save(void) if (trace->nb_trace_mem_list == 0) return rc; + rc = trace_mkdir(); + if (rc < 0) + return rc; + rc = trace_meta_save(trace); if (rc) return rc; diff --git a/lib/eal/common/eal_trace.h b/lib/eal/common/eal_trace.h index 06751eb23a..72a5a461ae 100644 --- a/lib/eal/common/eal_trace.h +++ b/lib/eal/common/eal_trace.h @@ -54,7 +54,7 @@ struct trace { char dir[PATH_MAX]; int dir_offset; int register_errno; - bool status; + uint32_t status; enum rte_trace_mode mode; rte_uuid_t uuid; uint32_t buff_len; @@ -104,7 +104,6 @@ void trace_uuid_generate(void); int trace_metadata_create(void); void trace_metadata_destroy(void); char *trace_metadata_fixup_field(const char *field); -int trace_mkdir(void); int trace_epoch_time_save(void); void trace_mem_free(void); void trace_mem_per_thread_free(void); -- 2.37.3