Обсуждение: Tab completion regression test failed on illumos
Hi hackers,
I try to run regression test on illumos, the 010_tab_completion will
failed because of timeout.
Here is my build commands and logs:
$ ../configure --enable-cassert --enable-debug --enable-nls --with-perl \
--with-python --with-tcl --with-openssl --with-libxml --with-libxslt \
--without-icu --enable-tap-tests --prefix=/home/japin/postgres/build/pg
$ make -j $(nproc)
...
$ cd src/bin/psql/ && make check
make -C ../../../src/backend generated-headers
make[1]: Entering directory '/home/japin/postgres/build/src/backend'
make -C catalog distprep generated-header-symlinks
make[2]: Entering directory '/home/japin/postgres/build/src/backend/catalog'
make[2]: Nothing to be done for 'distprep'.
make[2]: Nothing to be done for 'generated-header-symlinks'.
make[2]: Leaving directory '/home/japin/postgres/build/src/backend/catalog'
make -C nodes distprep generated-header-symlinks
make[2]: Entering directory '/home/japin/postgres/build/src/backend/nodes'
make[2]: Nothing to be done for 'distprep'.
make[2]: Nothing to be done for 'generated-header-symlinks'.
make[2]: Leaving directory '/home/japin/postgres/build/src/backend/nodes'
make -C utils distprep generated-header-symlinks
make[2]: Entering directory '/home/japin/postgres/build/src/backend/utils'
make[2]: Nothing to be done for 'distprep'.
make[2]: Nothing to be done for 'generated-header-symlinks'.
make[2]: Leaving directory '/home/japin/postgres/build/src/backend/utils'
make[1]: Leaving directory '/home/japin/postgres/build/src/backend'
rm -rf '/home/japin/postgres/build'/tmp_install
/opt/local/bin/mkdir -p '/home/japin/postgres/build'/tmp_install/log
make -C '../../..' DESTDIR='/home/japin/postgres/build'/tmp_install install
>'/home/japin/postgres/build'/tmp_install/log/install.log2>&1
make -j1 checkprep >>'/home/japin/postgres/build'/tmp_install/log/install.log 2>&1
PATH="/home/japin/postgres/build/tmp_install/home/japin/postgres/build/pg/bin:/home/japin/postgres/build/src/bin/psql:$PATH"
LD_LIBRARY_PATH="/home/japin/postgres/build/tmp_install/home/japin/postgres/build/pg/lib"
INITDB_TEMPLATE='/home/japin/postgres/build'/tmp_install/initdb-template initdb -A trust -N --no-instructions
--no-locale'/home/japin/postgres/build'/tmp_install/initdb-template
>>'/home/japin/postgres/build'/tmp_install/log/initdb-template.log2>&1
echo "# +++ tap check in src/bin/psql +++" && rm -rf '/home/japin/postgres/build/src/bin/psql'/tmp_check &&
/opt/local/bin/mkdir-p '/home/japin/postgres/build/src/bin/psql'/tmp_check && cd
/home/japin/postgres/build/../src/bin/psql&& TESTLOGDIR='/home/japin/postgres/build/src/bin/psql/tmp_check/log'
TESTDATADIR='/home/japin/postgres/build/src/bin/psql/tmp_check'
PATH="/home/japin/postgres/build/tmp_install/home/japin/postgres/build/pg/bin:/home/japin/postgres/build/src/bin/psql:$PATH"
LD_LIBRARY_PATH="/home/japin/postgres/build/tmp_install/home/japin/postgres/build/pg/lib"
INITDB_TEMPLATE='/home/japin/postgres/build'/tmp_install/initdb-template PGPORT='65432'
top_builddir='/home/japin/postgres/build/src/bin/psql/../../..'
PG_REGRESS='/home/japin/postgres/build/src/bin/psql/../../../src/test/regress/pg_regress'/opt/local/bin/prove -I
/home/japin/postgres/build/../src/test/perl/-I /home/japin/postgres/build/../src/bin/psql t/*.pl
# +++ tap check in src/bin/psql +++
t/001_basic.pl ........... ok
t/010_tab_completion.pl .. Dubious, test returned 25 (wstat 6400, 0x1900)
No subtests run
t/020_cancel.pl .......... ok
Test Summary Report
-------------------
t/010_tab_completion.pl (Wstat: 6400 Tests: 0 Failed: 0)
Non-zero exit status: 25
Parse errors: No plan found in TAP output
$ cat tmp_check/log/regress_log_010_tab_completion
# Checking port 59378
# Found port 59378
Name: main
Data directory: /home/japin/postgres/build/src/bin/psql/tmp_check/t_010_tab_completion_main_data/pgdata
Backup directory: /home/japin/postgres/build/src/bin/psql/tmp_check/t_010_tab_completion_main_data/backup
Archive directory: /home/japin/postgres/build/src/bin/psql/tmp_check/t_010_tab_completion_main_data/archives
Connection string: port=59378 host=/tmp/2tdG0Ck7Zb
Log file: /home/japin/postgres/build/src/bin/psql/tmp_check/log/010_tab_completion_main.log
[07:06:06.492](0.050s) # initializing database system by copying initdb template
# Running: cp -RPp /home/japin/postgres/build/tmp_install/initdb-template
/home/japin/postgres/build/src/bin/psql/tmp_check/t_010_tab_completion_main_data/pgdata
# Running: /home/japin/postgres/build/src/bin/psql/../../../src/test/regress/pg_regress --config-auth
/home/japin/postgres/build/src/bin/psql/tmp_check/t_010_tab_completion_main_data/pgdata
### Starting node "main"
# Running: pg_ctl -w -D /home/japin/postgres/build/src/bin/psql/tmp_check/t_010_tab_completion_main_data/pgdata -l
/home/japin/postgres/build/src/bin/psql/tmp_check/log/010_tab_completion_main.log-o --cluster-name=main start
waiting for server to start.... done
server started
# Postmaster PID for node "main" is 219980
#### Begin standard error
psql:<stdin>:6: WARNING: wal_level is insufficient to publish logical changes
HINT: Set wal_level to "logical" before creating subscriptions.
#### End standard error
IPC::Run: timeout on timer #1 at /opt/local/lib/perl5/vendor_perl/5.34.0/IPC/Run.pm line 2951. <-- HERE
# Postmaster PID for node "main" is 219980
### Stopping node "main" using mode immediate
# Running: pg_ctl -D /home/japin/postgres/build/src/bin/psql/tmp_check/t_010_tab_completion_main_data/pgdata -m
immediatestop
waiting for server to shut down.... done
server stopped
# No postmaster PID for node "main"
$ uname -a
SunOS db_build 5.11 xxxxx i86pc i386 i86pc illumos
$ perl --version
This is perl 5, version 34, subversion 0 (v5.34.0) built for x86_64-solaris-thread-multi-64
I try to change PG_TEST_TIMEOUT_DEFAULT to 600, it also failed with timeout.
Any suggestions? Thanks in advance!
--
Regrads,
Japin Li
ChengDu WenWu Information Technology Co., Ltd.
Hi, > I try to run regression test on illumos, the 010_tab_completion will > failed because of timeout. > > Here is my build commands and logs: > > [...] > > Any suggestions? Thanks in advance! It's hard to say what went wrong with this output due to lack of backtrace. I would suggest adding debug output to 010_tab_completion.pl to figure out on which line the script fails. Then I would figure out the exact command that failed. Then I would execute it manually and compare the result with my expectations. -- Best regards, Aleksander Alekseev
Japin Li <japinli@hotmail.com> writes:
> I try to run regression test on illumos, the 010_tab_completion will
> failed because of timeout.
Why are you getting this?
> #### Begin standard error
> psql:<stdin>:6: WARNING: wal_level is insufficient to publish logical changes
> HINT: Set wal_level to "logical" before creating subscriptions.
> #### End standard error
Not sure, but perhaps that unexpected output is confusing the test.
regards, tom lane
On Wed, Nov 01, 2023 at 03:19:39PM +0800, Japin Li wrote: > I try to run regression test on illumos, the 010_tab_completion will > failed because of timeout. > Any suggestions? Thanks in advance! This test failed for me, in a different way, when I briefly installed IO::Pty on a Solaris buildfarm member: https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=wrasse&dt=2023-01-03%2022%3A39%3A26 The IPC::Run pty tests also fail on Solaris. If I were debugging this, I'd start by fixing IO::Pty and IPC::Run to pass their own test suites on Solaris or illumos. Then I'd see if problems continue for this postgresql test.
On Thu, 02 Nov 2023 at 13:01, Noah Misch <noah@leadboat.com> wrote: > On Wed, Nov 01, 2023 at 03:19:39PM +0800, Japin Li wrote: >> I try to run regression test on illumos, the 010_tab_completion will >> failed because of timeout. > >> Any suggestions? Thanks in advance! > > This test failed for me, in a different way, when I briefly installed IO::Pty > on a Solaris buildfarm member: > https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=wrasse&dt=2023-01-03%2022%3A39%3A26 > Thanks for confirm this! I try to install IO::Pty using cpan, however, I cannot get the same error. > The IPC::Run pty tests also fail on Solaris. If I were debugging this, I'd > start by fixing IO::Pty and IPC::Run to pass their own test suites on Solaris > or illumos. Then I'd see if problems continue for this postgresql test. So, it might be a bug comes from Perl. -- Regrads, Japin Li ChengDu WenWu Information Technology Co., Ltd.
On Thu, 02 Nov 2023 at 13:42, Japin Li <japinli@hotmail.com> wrote: > On Thu, 02 Nov 2023 at 13:01, Noah Misch <noah@leadboat.com> wrote: >> On Wed, Nov 01, 2023 at 03:19:39PM +0800, Japin Li wrote: >>> I try to run regression test on illumos, the 010_tab_completion will >>> failed because of timeout. >> >>> Any suggestions? Thanks in advance! >> >> This test failed for me, in a different way, when I briefly installed IO::Pty >> on a Solaris buildfarm member: >> https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=wrasse&dt=2023-01-03%2022%3A39%3A26 >> > Thanks for confirm this! > > I try to install IO::Pty using cpan, however, I cannot get the same error. > >> The IPC::Run pty tests also fail on Solaris. If I were debugging this, I'd >> start by fixing IO::Pty and IPC::Run to pass their own test suites on Solaris >> or illumos. Then I'd see if problems continue for this postgresql test. > > So, it might be a bug comes from Perl. After enable debug for IPC::Run, I found the following logs: IPC::Run 0001 0123456789012-4 [#2(415745)]: writing to fd 11 (kid's stdin) IPC::Run 0001 0123456789012-4 [#2(415745)]: write( 11, 'SEL ' ) = 4 <- Here write 4 bytes. IPC::Run 0001 0123456789012-4 [#2(415745)]: fds for select: -----------r--r IPC::Run 0001 0123456789012-4 [#2(415745)]: timeout=0 IPC::Run 0001 0123456789012-4 [#2(415745)]: selected -----------r IPC::Run 0001 0123456789012-4 [#2(415745)]: filtering data from fd 11 (kid's stdout) IPC::Run 0001 0123456789012-4 [#2(415745)]: reading from fd 11 (kid's stdout) IPC::Run 0001 0123456789012-4 [#2(415745)]: read( 11 ) = 8 chars 'SEL ' <- But read 8 bytes. It seems the 'SEL\t' is converted to 'SEL ' which is "SEL" with 5 spaces. -- Regrads, Japin Li ChengDu WenWu Information Technology Co., Ltd.
Japin Li <japinli@hotmail.com> writes:
> It seems the 'SEL\t' is converted to 'SEL ' which is "SEL" with 5 spaces.
That would be plausible if readline were disabled, or otherwise
not functioning.
regards, tom lane
On Thu, 02 Nov 2023 at 22:23, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> Japin Li <japinli@hotmail.com> writes:
>> It seems the 'SEL\t' is converted to 'SEL ' which is "SEL" with 5 spaces.
>
> That would be plausible if readline were disabled, or otherwise
> not functioning.
>
I think this might be a bug comes from Illumos pseudo-tty. I can reproduce
this by using pseudo-tty on Illumos.
Here is a simple test case:
$ cat pseudo-tty.c
#define _XOPEN_SOURCE 600
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <unistd.h>
#include <fcntl.h>
#include <sys/types.h>
#include <sys/wait.h>
#define DEV_PTMX "/dev/ptmx"
int
main(void)
{
int ptm_fd;
pid_t pid;
char *pts_name;
ptm_fd = open(DEV_PTMX, O_RDWR);
grantpt(ptm_fd);
unlockpt(ptm_fd);
pts_name = ptsname(ptm_fd);
pid = fork();
if (pid == -1) {
fprintf(stderr, "could not fork a new process: %m\n");
close(ptm_fd);
return -1;
} else if (pid == 0) {
int pts_fd;
close(ptm_fd);
pts_fd = open(pts_name, O_RDWR);
write(pts_fd, "SEL\tH", 5);
close(pts_fd);
} else {
int status;
char buffer[512] = { 0 };
ssize_t bytes;
bytes = read(ptm_fd, buffer, sizeof(buffer));
printf("%ld: '%s'\n", bytes, buffer);
waitpid(pid, &status, 0);
close(ptm_fd);
}
return 0;
}
On IllumsOS
$ gcc -o pseudo-tty pseudo-tty.c
$ ./pseudo-tty
9: 'SEL H'
On Ubuntu
$ gcc -o pseudo-tty pseudo-tty.c
$ ./pseudo-tty
5: 'SEL H'
--
Regrads,
Japin Li
ChengDu WenWu Information Technology Co., Ltd.
On Fri, Nov 3, 2023 at 3:42 AM Japin Li <japinli@hotmail.com> wrote: > On Thu, 02 Nov 2023 at 22:23, Tom Lane <tgl@sss.pgh.pa.us> wrote: > > Japin Li <japinli@hotmail.com> writes: > >> It seems the 'SEL\t' is converted to 'SEL ' which is "SEL" with 5 spaces. > > > > That would be plausible if readline were disabled, or otherwise > > not functioning. > > > > I think this might be a bug comes from Illumos pseudo-tty. I can reproduce > this by using pseudo-tty on Illumos. I don't know but my guess is that this has to do with termios defaults being different. From a quick look at 'man termios', perhaps TABDLY is set to expand tabs to spaces? Can you fix it by tweaking the flags in src/common/sprompt.c? Somewhere near the line that disables ECHO, perhaps you can figure out how to disable that in c_oflag? This is all the ancient forgotten magic that allows all Unixes to drive 70 year old electric typewriters, inserting suitable pauses and converting various things as it goes.
On Fri, Nov 3, 2023 at 2:22 PM Thomas Munro <thomas.munro@gmail.com> wrote: > On Fri, Nov 3, 2023 at 3:42 AM Japin Li <japinli@hotmail.com> wrote: > > I think this might be a bug comes from Illumos pseudo-tty. I can reproduce > > this by using pseudo-tty on Illumos. > > I don't know but my guess is that this has to do with termios defaults > being different. From a quick look at 'man termios', perhaps TABDLY > is set to expand tabs to spaces? Can you fix it by tweaking the flags > in src/common/sprompt.c? Argh, sorry that's completely the wrong end. I suppose that sort of thing would have to happen in IPC::Run. I wonder what would happen if IPC::Run called ->set_raw() on the IO::Pty object it constructs, or failing that, if IO::Stty can be used to mess with the relevant settings.
On Fri, 03 Nov 2023 at 10:03, Thomas Munro <thomas.munro@gmail.com> wrote: > On Fri, Nov 3, 2023 at 2:22 PM Thomas Munro <thomas.munro@gmail.com> wrote: >> On Fri, Nov 3, 2023 at 3:42 AM Japin Li <japinli@hotmail.com> wrote: >> > I think this might be a bug comes from Illumos pseudo-tty. I can reproduce >> > this by using pseudo-tty on Illumos. >> >> I don't know but my guess is that this has to do with termios defaults >> being different. From a quick look at 'man termios', perhaps TABDLY >> is set to expand tabs to spaces? Can you fix it by tweaking the flags >> in src/common/sprompt.c? > > Argh, sorry that's completely the wrong end. I suppose that sort of > thing would have to happen in IPC::Run. I wonder what would happen if > IPC::Run called ->set_raw() on the IO::Pty object it constructs, or > failing that, if IO::Stty can be used to mess with the relevant > settings. Thanks for your explantation, the termios.c_oflag on Illumos enables TABDLY by default. -- Regrads, Japin Li ChengDu WenWu Information Technology Co., Ltd.
On Fri, Nov 3, 2023 at 3:14 PM Japin Li <japinli@hotmail.com> wrote: > Thanks for your explantation, the termios.c_oflag on Illumos enables TABDLY > by default. It seems that various other open source Unixen dropped that between 29 and 2 years ago, but not illumos. I guess no one ever had IO::Pty installed on an older OpenBSD or NetBSD machine or we'd have seen this problem there too, but as of a few years ago they behave like Linux and FreeBSD: no tab expansion. https://github.com/apple-oss-distributions/xnu/blob/1031c584a5e37aff177559b9f69dbd3c8c3fd30a/bsd/sys/ttydefaults.h#L79 https://github.com/freebsd/freebsd-src/commit/210df5b10c855161149dd7a1e88f610972f2afaa https://github.com/NetBSD/src/commit/44a07dbdbdcb2b9e14340856c8267dc659a0ebd8 https://github.com/openbsd/src/commit/818e463522f2237e9da1be8aa7958dcc8af28fca https://github.com/illumos/illumos-gate/blob/0f9b8dcfdb872a210003f6b077d091b793c24a6e/usr/src/uts/common/io/tty_common.c#L35