pg.ddx.io pgsql-bugs@postgresql.org mailing list archive
help / color / mirror / Atom feedBUG #16685: The ecpg thread/descriptor test fails sometimes on Windows
5+ messages / 3 participants
[nested] [flat]
Commits from this thread:
2020-10-24 21d36747d4 fd048e0cb5 bdc79ddd10 12a73f29ff f38b66ec05 379c43bdad 758b45e83b Fix ancient bug in ecpg's pthread_once() emulation for Windows.
* BUG #16685: The ecpg thread/descriptor test fails sometimes on Windows
@ 2020-10-24 04:05 PG Bug reporting form <noreply@postgresql.org>
0 siblings, 1 reply; 5+ messages in thread
From: PG Bug reporting form @ 2020-10-24 04:05 UTC (permalink / raw)
To: pgsql-bugs@lists.postgresql.org; +Cc: exclusion@gmail.com
The following bug has been logged on the website:
Bug reference: 16685
Logged by: Alexander Lakhin
Email address: exclusion@gmail.com
PostgreSQL version: 13.0
Operating system: Ubuntu 20.04
Description:
When running `vcregress ecpgcheck`, sometimes I get:
test thread/descriptor ... stderr FAILED 99 ms
regression.diffs contains:
--- .../src/interfaces/ecpg/test/expected/thread-descriptor.stderr
2019-12-04 16:05:46 +0300
+++ .../src/interfaces/ecpg/test/results/thread-descriptor.stderr
2020-10-20 10:00:34 +0300
@@ -0,0 +1 @@
+SQL error: descriptor "mydesc" not found on line 31
See also:
https://www.postgresql.org/message-id/flat/230799.1603045446%40sss.pgh.pa.us
In descriptor.pgc we have:
30: EXEC SQL ALLOCATE DESCRIPTOR mydesc;
31: EXEC SQL DEALLOCATE DESCRIPTOR mydesc;
So the mydesc descriptor disappeared somehow just after allocation.
`EXEC SQL DEALLOCATE DESCRIPTOR` and `EXEC SQL DEALLOCATE DESCRIPTOR` are
implemented in ECPGallocate_desc and ECPGdeallocate_desc in
ecpglib\descriptor.c, correspondingly, so I looked into the code.
I found that the get_descriptors() function called in ECPGdeallocate_desc
sometimes can return null.
static struct descriptor *
get_descriptors(void)
{
pthread_once(&descriptor_once, descriptor_key_init);
return (struct descriptor *) pthread_getspecific(descriptor_key);
}
pthread_getspecific(key) implemented on Widnows as TlsGetValue(key);
To make the bug reproduction easier, I replaced ecpg_schedule contents with
100 "test: thread/descriptor" lines and ran `vcregress ecpgcheck` in a loop
with 100 iterations. And with such setup it takes just several minutes to
get a failure.
The following debugging code inserted into the ECPGallocate_desc:
+++ b/src/interfaces/ecpg/ecpglib/descriptor.c
@@ -829,6 +829,17 @@ ECPGallocate_desc(int line, const char *name)
}
strcpy(new->name, name);
set_descriptors(new);
+
+ long initialdk = descriptor_key;
+ for (int n = 0; n < 1000; n++) {
+ void *new1 = TlsGetValue(descriptor_key);
+ if (!new1) {
+ DWORD lasterr = GetLastError();
+ fprintf(stdout, "TlsGetValue() returned null on
iteration %d, error: %d, descriptor_key: %d, initial descriptor_key:
%d.\n",
+ n, lasterr, descriptor_key,
initialdk);
+ exit(2);
+ }
+ }
return true;
}
shows on a failure:
TlsGetValue() returned null on iteration 209, error: 0, descriptor_key: 28,
initial descriptor_key: 0.
or
TlsGetValue() returned null on iteration: 369, error: 0, descriptor_key: 28,
initial descriptor_key: 0
So the descriptor_key changed after set_descriptors(new), and following
get_descriptors() would return null as seen on a test failure.
^ permalink raw reply [nested|flat] 5+ messages in thread
* Re: BUG #16685: The ecpg thread/descriptor test fails sometimes on Windows
@ 2020-10-24 15:50 Tom Lane <tgl@sss.pgh.pa.us>
parent: PG Bug reporting form <noreply@postgresql.org>
0 siblings, 1 reply; 5+ messages in thread
From: Tom Lane @ 2020-10-24 15:50 UTC (permalink / raw)
To: exclusion@gmail.com; +Cc: pgsql-bugs@lists.postgresql.org
PG Bug reporting form <noreply@postgresql.org> writes:
> I found that the get_descriptors() function called in ECPGdeallocate_desc
> sometimes can return null.
> The following debugging code inserted into the ECPGallocate_desc:
> ...
> shows on a failure:
> TlsGetValue() returned null on iteration 209, error: 0, descriptor_key: 28,
> initial descriptor_key: 0.
> or
> TlsGetValue() returned null on iteration: 369, error: 0, descriptor_key: 28,
> initial descriptor_key: 0
Hm. I'm supposing that 0 isn't likely to be the correct TLS index,
and what this is showing us is that we got here before anyone had
done descriptor_key_init.
I'll bet that the correct fix is
static void
set_descriptors(struct descriptor *value)
{
+ pthread_once(&descriptor_once, descriptor_key_init);
pthread_setspecific(descriptor_key, value);
}
and that you could probably reproduce this on non-Windows, too,
if you tried hard (sticking a delay in get_descriptors might do it).
regards, tom lane
^ permalink raw reply [nested|flat] 5+ messages in thread
* Re: BUG #16685: The ecpg thread/descriptor test fails sometimes on Windows
@ 2020-10-24 16:54 Tom Lane <tgl@sss.pgh.pa.us>
parent: Tom Lane <tgl@sss.pgh.pa.us>
0 siblings, 1 reply; 5+ messages in thread
From: Tom Lane @ 2020-10-24 16:54 UTC (permalink / raw)
To: exclusion@gmail.com; +Cc: pgsql-bugs@lists.postgresql.org
I wrote:
> I'll bet that the correct fix is
> static void
> set_descriptors(struct descriptor *value)
> {
> + pthread_once(&descriptor_once, descriptor_key_init);
> pthread_setspecific(descriptor_key, value);
> }
No, looking closer, there are only two calls of set_descriptors()
and each of them is preceded by a call to get_descriptors().
So it should not be possible to get here without descriptor_key
having been initialized.
I'm forced to the conclusion that there's something wrong with
ECPG's emulation of pthread_once ...
... and now that I look at it, it seems just as obvious what
is wrong there:
void
win32_pthread_once(volatile pthread_once_t *once, void (*fn) (void))
{
if (!*once)
{
pthread_mutex_lock(&win32_pthread_once_lock);
if (!*once)
{
*once = true;
fn();
}
pthread_mutex_unlock(&win32_pthread_once_lock);
}
}
We should not set *once until AFTER we execute fn().
Otherwise, other threads passing through pthread_once()
will mistakenly fall through, expecting the initialization
to be done already.
(So in this view, adding a sleep just before fn() would
make the failure more reproducible.)
regards, tom lane
^ permalink raw reply [nested|flat] 5+ messages in thread
* Re: BUG #16685: The ecpg thread/descriptor test fails sometimes on Windows
@ 2020-10-24 18:00 Alexander Lakhin <exclusion@gmail.com>
parent: Tom Lane <tgl@sss.pgh.pa.us>
0 siblings, 1 reply; 5+ messages in thread
From: Alexander Lakhin @ 2020-10-24 18:00 UTC (permalink / raw)
To: Tom Lane <tgl@sss.pgh.pa.us>; +Cc: pgsql-bugs@lists.postgresql.org
24.10.2020 19:54, Tom Lane wrote:
> I'm forced to the conclusion that there's something wrong with
> ECPG's emulation of pthread_once ...
>
> ... and now that I look at it, it seems just as obvious what
> is wrong there:
>
> void
> win32_pthread_once(volatile pthread_once_t *once, void (*fn) (void))
> {
> if (!*once)
> {
> pthread_mutex_lock(&win32_pthread_once_lock);
> if (!*once)
> {
> *once = true;
> fn();
> }
> pthread_mutex_unlock(&win32_pthread_once_lock);
> }
> }
>
> We should not set *once until AFTER we execute fn().
> Otherwise, other threads passing through pthread_once()
> will mistakenly fall through, expecting the initialization
> to be done already.
>
> (So in this view, adding a sleep just before fn() would
> make the failure more reproducible.)
Yes, adding "pg_usleep(1000L);" just before fn() leads to 15 of 100
tests failed (without the delay more than 100 iterations could pass
successfully).
And the reverse test construction:
fn();
pg_usleep(1000L);
*once = true;
Makes all the tests (I ran 30x100 iterations) pass just fine.
Thank you for looking into this!
Best regards,
Alexander
^ permalink raw reply [nested|flat] 5+ messages in thread
* Re: BUG #16685: The ecpg thread/descriptor test fails sometimes on Windows
@ 2020-10-24 20:41 Tom Lane <tgl@sss.pgh.pa.us>
parent: Alexander Lakhin <exclusion@gmail.com>
0 siblings, 0 replies; 5+ messages in thread
From: Tom Lane @ 2020-10-24 20:41 UTC (permalink / raw)
To: Alexander Lakhin <exclusion@gmail.com>; +Cc: pgsql-bugs@lists.postgresql.org
BTW, I searched the buildfarm logs of ECPG failures to see if I could
find anything related to this, and noticed that there were a fair
number of Windows-machine failures in the thread/prep test. They don't
all look quite alike, but this one is representative (and the most
recent):
sysname|dory
snapshot|2019-04-02 11:20:25
================== pgsql.build/src/interfaces/ecpg/test/regression.diffs ===================
inline patch 1: c:/pgbuildfarm/pgbuildroot/HEAD/pgsql.build/src/interfaces/ecpg/test/results/thread-prep.stderr (+10/-0 lines) download inline-1.patch
diff -w -U3 c:/pgbuildfarm/pgbuildroot/HEAD/pgsql.build/src/interfaces/ecpg/test/expected/thread-prep.stderr c:/pgbuildfarm/pgbuildroot/HEAD/pgsql.build/src/interfaces/ecpg/test/results/thread-prep.stderr
--- c:/pgbuildfarm/pgbuildroot/HEAD/pgsql.build/src/interfaces/ecpg/test/expected/thread-prep.stderr 2018-04-20 16:03:08 -0400
+++ c:/pgbuildfarm/pgbuildroot/HEAD/pgsql.build/src/interfaces/ecpg/test/results/thread-prep.stderr 2019-04-02 07:43:27 -0400
@@ -0,0 +1,84 @@
+SQL error: could not connect to database "ecpg1_regression" on line 48
+SQL error: the connection to the server was lost on line 53
+SQL error: the connection to the server was lost on line 52
+SQL error: invalid statement name "i" on line 53
+SQL error: the connection to the server was lost on line 52
+SQL error: invalid statement name "i" on line 53
+SQL error: the connection to the server was lost on line 52
+SQL error: invalid statement name "i" on line 53
+SQL error: the connection to the server was lost on line 52
+SQL error: invalid statement name "i" on line 53
end of thread, other threads:[~2020-10-24 20:41 UTC | newest]
Thread overview: 5+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2020-10-24 04:05 BUG #16685: The ecpg thread/descriptor test fails sometimes on Windows PG Bug reporting form <noreply@postgresql.org>
2020-10-24 15:50 ` Tom Lane <tgl@sss.pgh.pa.us>
2020-10-24 16:54 ` Tom Lane <tgl@sss.pgh.pa.us>
2020-10-24 18:00 ` Alexander Lakhin <exclusion@gmail.com>
2020-10-24 20:41 ` Tom Lane <tgl@sss.pgh.pa.us>
This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox