Subject: pgbench error: (setshell) of script 0; execution of meta-command failed

From: Andy Fan <[email-masked]>
Date: Fri, 10 Jan 2025 02:45:21 +0000

Hi:

I run into the {subject} issue with the below setup.

cat foo.sql

\setshell txn_mode echo ${TXN_MODE}
\setshell speed echo ${SPEED}
\setshell sleep_ms echo ${SLEEP_MS}
\setshell subtxn_mode echo ${SUBTXN_MODE}

select 1;

$ TXN_MODE=-1 SPEED=1 SLEEP_MS=0 SUBTXN_MODE=-1 pgbench -n -ffoo.sql postgres -T5 -c4 --exit-on-abort

I *randomly*(7/8) get errors like:

pgbench (18devel)
pgbench: error: client 2 aborted in command 0 (setshell) of script 0; execution of meta-command failed
pgbench: error: Run was aborted due to an error in thread 0

I debug this for 1+ hour and didn't find anything useful, so I'd like
have a ask if there is any known issue or the way I use \setshell is
wrong?

Thanks

-- 
Best Regards
Andy Fan

---

From: Andy Fan <[email-masked]>
Date: Fri, 10 Jan 2025 07:09:52 +0000

> pgbench: error: Run was aborted due to an error in thread 0

I think I have figured out the issue, if you want reproduce it quicker,
you can change the '-T5' to '-T1' in the pgbench command and run many times.

Here is the patch to fix it, would someone take a look at? 

    pgbench: Avoid misleading error for \[set]shell when timer_exceeded.
    
    fgets in executeMetaCommand may return NULL if it receives a signal
    during the shell command is executing. Before this commit, pgbench
    client raises ERROR like below.
    
    pgbench: error: client 3 aborted in command 3 (setshell) of script 0;
    execution of meta-command failed
    
    This behavior is misleading since people may think something is
    wrong. In this commit, we just ignore fgets return NULL when
    timer_exceeded.

-- 
Best Regards
Andy Fan

>From 9b03ff66e45d019631ed9fd3322c0911ce14a8a7 Mon Sep 17 00:00:00 2001
From: Andy Fan <[email-masked]>
Date: Fri, 10 Jan 2025 06:56:11 +0000
Subject: [PATCH 1/1] pgbench: Avoid misleading error for \[set]shell when
 timer_exceeded.

fgets in executeMetaCommand may return NULL if it receives a signal
during the shell command is executing. Before this commit, pgbench
client raises ERROR like below.

pgbench: error: client 3 aborted in command 3 (setshell) of script 0;
execution of meta-command failed

This behavior is misleading since people may think something is
wrong. In this commit, we just ignore fgets return NULL when
timer_exceeded.
---
 src/bin/pgbench/pgbench.c | 8 +++++++-
 1 file changed, 7 insertions(+), 1 deletion(-)

diff --git a/src/bin/pgbench/pgbench.c b/src/bin/pgbench/pgbench.c
index c415e0f32c..7f61cd3aea 100644
--- a/src/bin/pgbench/pgbench.c
+++ b/src/bin/pgbench/pgbench.c
@@ -3851,7 +3851,9 @@ advanceConnectionState(TState *thread, CState *st, StatsData *agg)
 				Assert(st->state == CSTATE_WAIT_RESULT ||
 					   st->state == CSTATE_END_COMMAND ||
 					   st->state == CSTATE_SLEEP ||
-					   st->state == CSTATE_ABORTED);
+					   st->state == CSTATE_ABORTED ||
+					   st->state == CSTATE_FINISHED);
+
 				break;
 
 				/*
@@ -4414,6 +4416,8 @@ executeMetaCommand(CState *st, pg_time_usec_t *now)
 	{
 		if (!runShellCommand(&st->variables, argv[1], argv + 2, argc - 2))
 		{
+			if (timer_exceeded)
+				return CSTATE_FINISHED;
 			commandFailed(st, "setshell", "execution of meta-command failed");
 			return CSTATE_ABORTED;
 		}
@@ -4422,6 +4426,8 @@ executeMetaCommand(CState *st, pg_time_usec_t *now)
 	{
 		if (!runShellCommand(&st->variables, NULL, argv + 1, argc - 1))
 		{
+			if (timer_exceeded)
+				return CSTATE_FINISHED;
 			commandFailed(st, "shell", "execution of meta-command failed");
 			return CSTATE_ABORTED;
 		}
-- 
2.45.1

---

From: Fujii Masao <[email-masked]>
Date: Fri, 10 Jan 2025 21:41:21 +0900

>> pgbench: error: Run was aborted due to an error in thread 0

Interestingly, my git bisect pointed to the following commit
as the cause of this issue, even though it seems unrelated to
the pgbench problem at all. It’s possible my git bisect result
is incorrect, but when I reverted this commit on HEAD,
the pgbench issue didn’t occur during my tests.

----------------------
06843df4abc5a0c24e4bd154a8a1327e074fa3ae is the first bad commit
commit 06843df4abc5a0c24e4bd154a8a1327e074fa3ae
Author: Tom Lane <[email-masked]>
Date:   Fri Sep 29 14:07:30 2023 -0400

     Suppress macOS warnings about duplicate libraries in link commands.
----------------------

Regards,

-- 
Fujii Masao
Advanced Computing Technology Center
Research and Development Headquarters
NTT DATA CORPORATION

---

From: Fujii Masao <[email-masked]>
Date: Fri, 10 Jan 2025 23:39:13 +0900

> the pgbench issue didn’t occur during my tests.

Before this commit, pgbench used pqsignal() from port/pqsignal.c
to set the signal handler for SIGALRM. This version of pqsignal()
sets SA_RESTART for frontend code, so fgets() in runShellCommand()
wouldn't return NULL even if SIGALRM arrived during fgets(),
preventing the reported error.

On the other hand, currently, pgbench seems to use pqsignal()
from legacy-pqsignal.c, which doesn't set SA_RESTART for SIGALRM.
As a result, SIGALRM can interrupt fgets() in runShellCommand()
and make it return NULL, leading to the reported error.

I'm not sure if this change was an intentional result of that commit...

Regards,

---

From: Tom Lane <[email-masked]>
Date: Fri, 10 Jan 2025 09:57:45 -0500

> and make it return NULL, leading to the reported error.

Oh, interesting.

> I'm not sure if this change was an intentional result of that commit...

Definitely not.  I think we'd better look into how to undo that
effect.

Since legacy-pqsignal is really not supposed to be used by clients
anymore, maybe we could just adjust it to set SA_RESTART for SIGALRM?
The other alternatives I can think of amount to re-introducing
link order dependencies, which would be horrid.

			regards, tom lane