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 D2D09A00C2 for ; Thu, 13 Oct 2022 17:51:54 +0200 (CEST) Received: from [217.70.189.124] (localhost [127.0.0.1]) by mails.dpdk.org (Postfix) with ESMTP id CA6934301D; Thu, 13 Oct 2022 17:51:54 +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 667F842F7F for ; Thu, 13 Oct 2022 17:51:52 +0200 (CEST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=redhat.com; s=mimecast20190719; t=1665676311; 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: in-reply-to:in-reply-to:references:references; bh=XDlHFKVU/Rt9xAuqcskbqqnH7snbnRhKzKmI1r6vTsI=; b=EGvUAZgpxGtZa0RArciz9RNOYVM6uX16I5vWCrv0f1LePQV6b3pzBrA6KLTgpMsbNnO5qQ teFQp2jtzSSrLh+dnaQ3QwvBQm6oAkcD5Id6JWgSo4SNFCJLxR3uvGqpHvHQg/9jGP4oxu TxpKFVUqy/404WrUy84wueIUHvSsydg= Received: from mail-pg1-f200.google.com (mail-pg1-f200.google.com [209.85.215.200]) by relay.mimecast.com with ESMTP with STARTTLS (version=TLSv1.3, cipher=TLS_AES_128_GCM_SHA256) id us-mta-378-pemWGV0HPrOaXyhccjRC-Q-1; Thu, 13 Oct 2022 11:51:50 -0400 X-MC-Unique: pemWGV0HPrOaXyhccjRC-Q-1 Received: by mail-pg1-f200.google.com with SMTP id g66-20020a636b45000000b0043a256d3639so1184058pgc.12 for ; Thu, 13 Oct 2022 08:51:50 -0700 (PDT) X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20210112; h=cc:to:subject:message-id:date:from:in-reply-to:references :mime-version:x-gm-message-state:from:to:cc:subject:date:message-id :reply-to; bh=XDlHFKVU/Rt9xAuqcskbqqnH7snbnRhKzKmI1r6vTsI=; b=jtWOXAVinUKgeF2Diyui/b4Ki1/kX9JBooZo5r24GtWp9ol68mLeMN5j/JyMYGOln+ x4l9RavgP6Ga0boSe1BjRkqErPLWijSK0rpOtNG7LyIhQMD1lG0fw4vEjDaQLQeczFNG 1NrwpXCHvxs0zb9sX/3OVwAlciK1QaoN9lGjhJjltKppW92y8Hxu+11EzqQS1NyHQdSW sREIgiT4jlYklkbF7p510dzKo4w3vMBAdAaVNGSvl1/msCAzxhs5QQctKKGcuNRpxS93 bI2ih/NLOaQBlv7LvmKxlN9uCes3r+0XhHJ/Zx085zX8QQBNp5z7ruDbFPqyJpozgruc BycA== X-Gm-Message-State: ACrzQf3rVUnonj+OfE+6nGQzd/RGEjf/18juh9cunF9F/WDG1xr01fmk V9tTQLEsFFI1EPwZvWvku8bQ/yC8NOVMwRpZa8n5M5Ws72rftcj/bOksy7eb0E9gEK5yDO59yHO fPWPrY9MWVwueMd9KeTOdeYc= X-Received: by 2002:a17:90b:1c8e:b0:205:783b:fe32 with SMTP id oo14-20020a17090b1c8e00b00205783bfe32mr12321593pjb.39.1665676309144; Thu, 13 Oct 2022 08:51:49 -0700 (PDT) X-Google-Smtp-Source: AMsMyM5aGARlVIbPx7SGbJFeKhNbbJt4jXNgqKVfiWxuuKtNMskJbn8kJirhLOXEV+rsFR+shKzZm5b2HYMmJnScJ/c= X-Received: by 2002:a17:90b:1c8e:b0:205:783b:fe32 with SMTP id oo14-20020a17090b1c8e00b00205783bfe32mr12321556pjb.39.1665676308824; Thu, 13 Oct 2022 08:51:48 -0700 (PDT) MIME-Version: 1.0 References: <20220921120359.2201131-1-david.marchand@redhat.com> <20221012123112.2951802-1-david.marchand@redhat.com> <20221012123112.2951802-6-david.marchand@redhat.com> In-Reply-To: From: David Marchand Date: Thu, 13 Oct 2022 17:51:36 +0200 Message-ID: Subject: Re: [EXT] [PATCH v3 5/9] trace: fix dynamically enabling trace points To: Harman Kalra Cc: "dev@dpdk.org" , Jerin Jacob Kollanukkaran , Sunil Kumar Kori , "stable@dpdk.org" X-Mimecast-Spam-Score: 0 X-Mimecast-Originator: redhat.com Content-Type: text/plain; charset="UTF-8" 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 On Thu, Oct 13, 2022 at 4:53 PM Harman Kalra wrote: > > > > -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; > > + > Hi David > > I was trying out "trace: take live traces via telemetry" patch > I came across following scenario > - Started testpmd with trace=.* > - Executed /trace/save from telemetry script, trace file saved successfully > - Later after stopping application, rte_eal_cleanup() did not save the trace. > > With this we lost traces after /trace/save executed Sorry, I must be missing something. What patches did you apply and how are you testing? With the whole traces fixes series applied first, then the new "trace: take live traces via telemetry" patch applied, I can't reproduce your issue. Here is what I did: $ ./build/app/dpdk-testpmd -c 3 --no-huge -m 40 -a 0:0.0 -d build-gcc/drivers --vdev net_null1 --vdev net_null2 --trace=.* -- --no-mlockall --total-num-mbufs=2048 -ia --> /trace/save {"/trace/save": {"Status": "OK", "Path": "/home/dmarchan/dpdk-traces/rte-2022-10-13-PM-05-44-56"}} At this point, the trace file contains events until: ... [17:44:50.738892453] (+0.000000154) lib.eal.mem.malloc: { cpu_id = 0x0, name = "dpdk-testpmd" }, { type = "", size = 0x0, align = 0x0, socket = 0, ptr = 0x0 } [17:44:50.738892470] (+0.000000017) lib.eal.mem.zmalloc: { cpu_id = 0x0, name = "dpdk-testpmd" }, { type = "", size = 0x0, align = 0x0, socket = 0, ptr = 0x0 } [17:44:50.738894858] (+0.000002388) lib.eal.mem.malloc: { cpu_id = 0x0, name = "dpdk-testpmd" }, { type = "", size = 0x0, align = 0x0, socket = 0, ptr = 0x0 } [17:44:50.738894881] (+0.000000023) lib.eal.mem.zmalloc: { cpu_id = 0x0, name = "dpdk-testpmd" }, { type = "", size = 0x0, align = 0x0, socket = 0, ptr = 0x0 } [17:44:50.738894899] (+0.000000018) lib.ethdev.rxq.setup: { cpu_id = 0x0, name = "dpdk-testpmd" }, { port_id = 0x1, rx_queue_id = 0x0, nb_rx_desc = 0x200, mp = 0x101A9E540, rx_conf_rx_thresh_pthresh = 0x0, rx_conf_rx_thresh_hthresh = 0x0, rx_conf_rx_thresh_wthresh = 0x0, rx_conf_rx_drop_en = 0x0, rx_conf_rx_deferred_start = 0x0, rx_conf_offloads = 0x0, rc = 0 } [17:44:50.738895490] (+0.000000591) lib.ethdev.start: { cpu_id = 0x0, name = "dpdk-testpmd" }, { port_id = 0x1 } [17:44:50.738908652] (+0.000013162) lib.eal.memzone.lookup: { cpu_id = 0x0, name = "dpdk-testpmd" }, { name = "RTE_METRICS", memzone = 0x0 } [17:44:50.738912231] (+0.000003579) lib.eal.memzone.reserve: { cpu_id = 0x0, name = "dpdk-testpmd" }, { name = "RTE_METRICS", len = 0x15010, socket_id = 0, flags = 0x0, align = 0x40, bound = 0x0, mz = 0x100007168 } [17:44:50.779538885] (+0.040626654) lib.eal.thread.remote.launch: { cpu_id = 0x0, name = "dpdk-testpmd" }, { f = 0x458130, arg = 0x101C20780, worker_id = 0x1, rc = 0 } Then, I stop testpmd, and look again at the same trace file: ... [17:44:50.779538885] (+0.040626654) lib.eal.thread.remote.launch: { cpu_id = 0x0, name = "dpdk-testpmd" }, { f = 0x458130, arg = 0x101C20780, worker_id = 0x1, rc = 0 } [17:45:12.630581221] (+21.851042336) lib.ethdev.stop: { cpu_id = 0x0, name = "dpdk-testpmd" }, { port_id = 0x0, ret = 0 } [17:45:12.630590961] (+0.000009740) lib.ethdev.stop: { cpu_id = 0x0, name = "dpdk-testpmd" }, { port_id = 0x1, ret = 0 } [17:45:12.630601415] (+0.000010454) lib.ethdev.close: { cpu_id = 0x0, name = "dpdk-testpmd" }, { port_id = 0x0 } [17:45:12.630606931] (+0.000005516) lib.eal.mem.free: { cpu_id = 0x0, name = "dpdk-testpmd" }, { ptr = 0x10126D700 } [17:45:12.630618608] (+0.000011677) lib.eal.mem.free: { cpu_id = 0x0, name = "dpdk-testpmd" }, { ptr = 0x10126B680 } [17:45:12.630621015] (+0.000002407) lib.eal.mem.free: { cpu_id = 0x0, name = "dpdk-testpmd" }, { ptr = 0x0 } [17:45:12.630621038] (+0.000000023) lib.eal.mem.free: { cpu_id = 0x0, name = "dpdk-testpmd" }, { ptr = 0x0 } [17:45:12.630621062] (+0.000000024) lib.eal.mem.free: { cpu_id = 0x0, name = "dpdk-testpmd" }, { ptr = 0x102643B40 } [17:45:12.630668837] (+0.000047775) lib.ethdev.close: { cpu_id = 0x0, name = "dpdk-testpmd" }, { port_id = 0x1 } [17:45:12.630671206] (+0.000002369) lib.eal.mem.free: { cpu_id = 0x0, name = "dpdk-testpmd" }, { ptr = 0x101269480 } [17:45:12.630673731] (+0.000002525) lib.eal.mem.free: { cpu_id = 0x0, name = "dpdk-testpmd" }, { ptr = 0x101267400 } [17:45:12.630675638] (+0.000001907) lib.eal.mem.free: { cpu_id = 0x0, name = "dpdk-testpmd" }, { ptr = 0x0 } [17:45:12.630675662] (+0.000000024) lib.eal.mem.free: { cpu_id = 0x0, name = "dpdk-testpmd" }, { ptr = 0x0 } [17:45:12.630675685] (+0.000000023) lib.eal.mem.free: { cpu_id = 0x0, name = "dpdk-testpmd" }, { ptr = 0x10262F940 } [17:45:12.630712155] (+0.000036470) lib.eal.mem.free: { cpu_id = 0x0, name = "dpdk-testpmd" }, { ptr = 0x101C206C0 } [17:45:12.630712692] (+0.000000537) lib.mempool.free: { cpu_id = 0x0, name = "dpdk-testpmd" }, { mempool = 0x101A9E540, mempool_name = "mb_pool_0" } [17:45:12.630893367] (+0.000180675) lib.eal.mem.free: { cpu_id = 0x0, name = "dpdk-testpmd" }, { ptr = 0x101295F80 } [17:45:12.631196732] (+0.000303365) lib.eal.memzone.free: { cpu_id = 0x0, name = "dpdk-testpmd" }, { name = "MP_mb_pool_0_0", addr = 0x101295F80, rc = 0 } [17:45:12.631197557] (+0.000000825) lib.eal.mem.free: { cpu_id = 0x0, name = "dpdk-testpmd" }, { ptr = 0x101295EC0 } [17:45:12.631198085] (+0.000000528) lib.mempool.ops.free: { cpu_id = 0x0, name = "dpdk-testpmd" }, { mempool = 0x101A9E540, mempool_name = "mb_pool_0" } [17:45:12.631201058] (+0.000002973) lib.eal.mem.free: { cpu_id = 0x0, name = "dpdk-testpmd" }, { ptr = 0x101A96280 } [17:45:12.631202316] (+0.000001258) lib.eal.memzone.free: { cpu_id = 0x0, name = "dpdk-testpmd" }, { name = "RG_MP_mb_pool_0", addr = 0x101A96280, rc = 0 } [17:45:12.631203186] (+0.000000870) lib.eal.mem.free: { cpu_id = 0x0, name = "dpdk-testpmd" }, { ptr = 0x101A9E480 } [17:45:12.631203338] (+0.000000152) lib.eal.mem.free: { cpu_id = 0x0, name = "dpdk-testpmd" }, { ptr = 0x101A9E540 } [17:45:12.631263318] (+0.000059980) lib.eal.memzone.free: { cpu_id = 0x0, name = "dpdk-testpmd" }, { name = "MP_mb_pool_0", addr = 0x101A9E540, rc = 0 } [17:45:12.631525049] (+0.000261731) lib.eal.mem.free: { cpu_id = 0x0, name = "dpdk-testpmd" }, { ptr = 0x1026ABE80 } [17:45:12.631525323] (+0.000000274) lib.eal.mem.free: { cpu_id = 0x0, name = "dpdk-testpmd" }, { ptr = 0x102687E00 } > > This happened because "already_done" was set after rte_trace_save() called via telemetry. > Later rte_eal_cleanup returned from this point without saving later traces. > > What is the purpose of already_done flag? already_done is used to create the trace directory once, and log a message with this directory path once. -- David Marchand