From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org Received: from phobos.denx.de (phobos.denx.de [85.214.62.61]) (using TLSv1.2 with cipher ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits)) (No client certificate requested) by smtp.lore.kernel.org (Postfix) with ESMTPS id 1360EC433FE for ; Mon, 10 Oct 2022 20:54:01 +0000 (UTC) Received: from h2850616.stratoserver.net (localhost [IPv6:::1]) by phobos.denx.de (Postfix) with ESMTP id 49DDE84EEF; Mon, 10 Oct 2022 22:53:59 +0200 (CEST) Authentication-Results: phobos.denx.de; dmarc=pass (p=none dis=none) header.from=amarulasolutions.com Authentication-Results: phobos.denx.de; spf=pass smtp.mailfrom=u-boot-bounces@lists.denx.de Authentication-Results: phobos.denx.de; dkim=pass (1024-bit key; unprotected) header.d=amarulasolutions.com header.i=@amarulasolutions.com header.b="qy2Ao5fT"; dkim-atps=neutral Received: by phobos.denx.de (Postfix, from userid 109) id DC71484E35; Mon, 10 Oct 2022 22:53:56 +0200 (CEST) Received: from mail-wr1-x429.google.com (mail-wr1-x429.google.com [IPv6:2a00:1450:4864:20::429]) (using TLSv1.3 with cipher TLS_AES_128_GCM_SHA256 (128/128 bits)) (No client certificate requested) by phobos.denx.de (Postfix) with ESMTPS id 3267884EF4 for ; Mon, 10 Oct 2022 22:53:49 +0200 (CEST) Authentication-Results: phobos.denx.de; dmarc=pass (p=none dis=none) header.from=amarulasolutions.com Authentication-Results: phobos.denx.de; spf=pass smtp.mailfrom=francis.laniel@amarulasolutions.com Received: by mail-wr1-x429.google.com with SMTP id f11so18701972wrm.6 for ; Mon, 10 Oct 2022 13:53:49 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=amarulasolutions.com; s=google; h=content-transfer-encoding:mime-version:references:in-reply-to :message-id:date:subject:cc:to:from:from:to:cc:subject:date :message-id:reply-to; bh=X4WVZ56Wzo090yDitUGNe2mzIma1nQshLVpgJdY8T6s=; b=qy2Ao5fTv3JIIAEM3x7xYdo6XNH2/LKmskzd4iBVybHRVXVGWDdkap1xGMdRzscahk bamOd5bMvnfqsvCMsROTZgTnWlKLm1QgWq8h/ewrKwZc8NBam6xggYbYq6p2ph2g1AAx 1kN8Fo7ZMgMBWCix2hXT34zVb3yDFqKN2ae3o= X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20210112; h=content-transfer-encoding:mime-version:references:in-reply-to :message-id:date:subject:cc:to:from:x-gm-message-state:from:to:cc :subject:date:message-id:reply-to; bh=X4WVZ56Wzo090yDitUGNe2mzIma1nQshLVpgJdY8T6s=; b=QoDm2UChMVGOgeqU24SbRmhneTIG/Z4gga5UtWE9j2yXeNicxkH9vQjezXyUuF3ARj jc31+3PhK19IczfF9+Mxz2foVmsbFj+pQ64k2QNEF2DwU3EDHb8nkhLPOAYzg/duGK4l u4nqIEEYREm4GXiCV4btb6tyGOn2Y2oYxZQGNm96YbCqcgDoi/kJjV/uaA2PRj/Ssb11 4XPbCrwtxIRiEg+o4G/flJjxrHQdVSjSLlGbKxvdqPSxi8qh6iJTpbgn5m+diX7Zcveg wgeC1pfxVbQYh1g6zw9k2/itjOANr4QuvvnvDsS0r15sjBM0173WMGIySOG/7XwKjFhj IE0Q== X-Gm-Message-State: ACrzQf23kud22GRNb1ZDuAK0yKglXEdYFRpDTxGTJaDtAMYhLjiNecK5 KPiUlVDagPHyh0dKLtWDPJcPlw== X-Google-Smtp-Source: AMsMyM774NuwTNp+9C1ANE8S2s1Hb7Y1g0X80HYCgRNS8CaDmxDgvf7iAaUmfcadGIdo3myoKn+pBA== X-Received: by 2002:a5d:6da2:0:b0:22e:4244:953a with SMTP id u2-20020a5d6da2000000b0022e4244953amr12264723wrs.225.1665435228684; Mon, 10 Oct 2022 13:53:48 -0700 (PDT) Received: from pwmachine.numericable.fr (85-170-32-183.rev.numericable.fr. [85.170.32.183]) by smtp.gmail.com with ESMTPSA id ay34-20020a05600c1e2200b003b4de550e34sm4968829wmb.40.2022.10.10.13.53.47 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Mon, 10 Oct 2022 13:53:48 -0700 (PDT) From: Francis Laniel To: Tom Rini Cc: u-boot@lists.denx.de, Marek Behun , Michael Nazzareno Trimarchi , Simon Glass , Wolfgang Denk , Harald Seiler , Francis Laniel Subject: [PATCH] for debug purpose only: add print to debug odd behavior. Date: Mon, 10 Oct 2022 22:52:53 +0200 Message-Id: <20221010205253.21740-1-francis.laniel@amarulasolutions.com> X-Mailer: git-send-email 2.25.1 In-Reply-To: <20220617144931.GZ2484912@bill-the-cat> References: <20220617144931.GZ2484912@bill-the-cat> MIME-Version: 1.0 Content-Transfer-Encoding: 8bit X-BeenThere: u-boot@lists.denx.de X-Mailman-Version: 2.1.39 Precedence: list List-Id: U-Boot discussion List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: u-boot-bounces@lists.denx.de Sender: "U-Boot" X-Virus-Scanned: clamav-milter 0.103.6 at phobos.denx.de X-Virus-Status: Clean Hi. I am really sorry for the delay in answer. Sadly, I am not able to send a v5 for the moment. Indeed, I am still struggling with the same bug since a lot of time... It happens in the Azure pipeline but also locally with test.py. I am sure the bug is related to memory management as the setexpr test fails because more memory is released than what expected (as shown by the debug message printed in this patch). Nonetheless, I am not able to say what is the root cause of it... I think this is a side effect "somewhere", as commenting out the "loop_i=" in the unit test for loop makes the tests pass. Sometime ago, it happened with sandbox and sandbox_clang and with a recent rebase it stopped happening on these boards but begins to occur on sandbox_flattree. I checked the behavior of the code related to loop and particularly what is done by set_local_var_2021() with GDB and I did not find any uncorrect behavior. I am sorry but I do not have a lot of other choices than asking for a bit of help as I really want to tackle this but I am lacking ideas... So, did such a bug already occur in U-Boot development process? If so, what was the root cause and what was done to help finding it? Best regards and thank you in advance as any help will be really appreciated. --- cmd/nvedit.c | 7 ++++++- cmd/setexpr.c | 4 ++++ common/cli_hush_upstream.c | 28 ++++++++++++++++++++++++++++ common/command.c | 4 ++++ include/cli_hush.h | 4 ++++ test/cmd/setexpr.c | 8 ++++++++ test/hush/loop.c | 3 +++ 7 files changed, 57 insertions(+), 1 deletion(-) diff --git a/cmd/nvedit.c b/cmd/nvedit.c index 53e6b57b60..cf6ac9d7f2 100644 --- a/cmd/nvedit.c +++ b/cmd/nvedit.c @@ -40,6 +40,8 @@ #include #include #include +#include +#include DECLARE_GLOBAL_DATA_PTR; @@ -275,8 +277,9 @@ static int _do_env_set(int flag, int argc, char *const argv[], int env_flag) */ for (i = 2, len = 0; i < argc; ++i) len += strlen(argv[i]) + 1; - + debug_foo("\t\t\t%s: before malloc: ut_check_free(): %lu\n", __func__, ut_check_free()); value = malloc(len); +// debug_foo("\t\t\t%s: after malloc: ut_check_free(): %lu\n", __func__, ut_check_free()); if (value == NULL) { printf("## Can't malloc %d bytes\n", len); return 1; @@ -294,7 +297,9 @@ static int _do_env_set(int flag, int argc, char *const argv[], int env_flag) e.key = name; e.data = value; hsearch_r(e, ENV_ENTER, &ep, &env_htab, env_flag); +// debug_foo("\t\t\t%s: before free: ut_check_free(): %lu\n", __func__, ut_check_free()); free(value); + debug_foo("\t\t\t%s: after free: ut_check_free(): %lu\n", __func__, ut_check_free()); if (!ep) { printf("## Error inserting \"%s\" variable, errno=%d\n", name, errno); diff --git a/cmd/setexpr.c b/cmd/setexpr.c index 4d671e7ef1..a815dba4f7 100644 --- a/cmd/setexpr.c +++ b/cmd/setexpr.c @@ -18,6 +18,8 @@ #include #include #include "printf.h" +#include +#include #define MAX_STR_LEN 128 @@ -412,7 +414,9 @@ static int do_setexpr(struct cmd_tbl *cmdtp, int flag, int argc, /* plain assignment: "setexpr name value" */ if (argc == 3) { if (w == CMD_DATA_SIZE_STR) { + debug_foo("\t\t%s: before env_set: ut_check_free(): %lu\n", __func__, ut_check_free()); ret = env_set(argv[1], aval.sval); + debug_foo("\t\t%s: after env_set: ut_check_free(): %lu\n", __func__, ut_check_free()); free(aval.sval); } else { ret = env_set_hex(argv[1], aval.ival); diff --git a/common/cli_hush_upstream.c b/common/cli_hush_upstream.c index bf7e51f2f3..14c1b8dc19 100644 --- a/common/cli_hush_upstream.c +++ b/common/cli_hush_upstream.c @@ -381,6 +381,10 @@ #endif #endif /* !__U_BOOT__ */ +#ifdef __U_BOOT__ +#include +#endif + /* So far, all bash compat is controlled by one config option */ /* Separate defines document which part of code implements what */ #define BASH_PATTERN_SUBST ENABLE_HUSH_BASH_COMPAT @@ -9760,6 +9764,28 @@ static int redirect_and_varexp_helper( } #endif /* !__U_BOOT__ */ +bool foo = false; + +void set_debug_foo(void) +{ + foo = true; +} + +void reset_debug_foo(void) +{ + foo = false; +} + +void debug_foo(char *fmt, ...) +{ + if (foo) { + va_list args; + va_start(args, fmt); + vprintf(fmt, args); + va_end(args); + } +} + static NOINLINE int run_pipe(struct pipe *pi) { static const char *const null_ptr = NULL; @@ -10269,9 +10295,11 @@ static NOINLINE int run_pipe(struct pipe *pi) next_infd = pipefds.rd; #else /* __U_BOOT__ */ /* Process the command */ + debug_foo("%s: before cmd_process: ut_check_free(): %lu\n", __func__, ut_check_free()); rcode = cmd_process(G.do_repeat ? CMD_FLAG_REPEAT : 0, command->argc, command->argv, &(G.flag_repeat), NULL); + debug_foo("%s: after cmd_process: ut_check_free(): %lu\n", __func__, ut_check_free()); if (argv_expanded) { /* diff --git a/common/command.c b/common/command.c index 41c91c6d8c..16660d3884 100644 --- a/common/command.c +++ b/common/command.c @@ -16,6 +16,8 @@ #include #include #include +#include +#include DECLARE_GLOBAL_DATA_PTR; @@ -577,7 +579,9 @@ static int cmd_call(struct cmd_tbl *cmdtp, int flag, int argc, { int result; + debug_foo("\t%s: before cmd function: ut_check_free(): %lu\n", __func__, ut_check_free()); result = cmdtp->cmd_rep(cmdtp, flag, argc, argv, repeatable); + debug_foo("\t%s: after cmd function: ut_check_free(): %lu\n", __func__, ut_check_free()); if (result) debug("Command failed, result=%d\n", result); return result; diff --git a/include/cli_hush.h b/include/cli_hush.h index 6261aa1806..623b023fdd 100644 --- a/include/cli_hush.h +++ b/include/cli_hush.h @@ -12,6 +12,10 @@ #define FLAG_REPARSING (1 << 2) /* >=2nd pass */ #define FLAG_CONT_ON_NEWLINE (1 << 3) /* continue when we see \n */ +void set_debug_foo(void); +void reset_debug_foo(void); +void debug_foo(char *fmt, ...); + #if CONFIG_IS_ENABLED(HUSH_OLD_PARSER) extern int u_boot_hush_start(void); extern int parse_string_outer(const char *, int); diff --git a/test/cmd/setexpr.c b/test/cmd/setexpr.c index 0dc94f7e61..bf15c0a1b5 100644 --- a/test/cmd/setexpr.c +++ b/test/cmd/setexpr.c @@ -9,6 +9,7 @@ #include #include #include +#include #include #include #include @@ -304,12 +305,19 @@ static int setexpr_test_str(struct unit_test_state *uts) ut_asserteq(1, run_command("setexpr.s fred 0", 0)); ut_assertok(ut_check_delta(start_mem)); + ut_unsilence_console(uts); + ut_assertok(env_set("fred", "12345")); start_mem = ut_check_free(); + + set_debug_foo(); ut_assertok(run_command("setexpr.s fred *0", 0)); + reset_debug_foo(); ut_asserteq_str("hello", env_get("fred")); ut_assertok(ut_check_delta(start_mem)); + ut_silence_console(uts); + unmap_sysmem(buf); return 0; diff --git a/test/hush/loop.c b/test/hush/loop.c index 8803dc6ae4..ab849f7fac 100644 --- a/test/hush/loop.c +++ b/test/hush/loop.c @@ -26,6 +26,9 @@ static int hush_test_for(struct unit_test_state *uts) if (gd->flags & GD_FLG_HUSH_2021_PARSER) { /* Reset local variable. */ + /* + * BUG Comment this below line out make the tests pass. + */ ut_assertok(run_command("loop_i=", 0)); } else if (gd->flags & GD_FLG_HUSH_OLD_PARSER) { puts("Beware: this test set local variable loop_i and it cannot be unset!"); -- 2.25.1