Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

perl-5.36.0 test lib/Benchmark.t has no exit. #20839

Closed
blastwave opened this issue Feb 21, 2023 · 12 comments
Closed

perl-5.36.0 test lib/Benchmark.t has no exit. #20839

blastwave opened this issue Feb 21, 2023 · 12 comments
Assignees

Comments

@blastwave
Copy link

Description

perl-5.36.0 test lib/Benchmark.t has no exit.

Steps to Reproduce

Perform a compile of 5.36.0 and then run the testsuite.

Expected behavior

 ? unknown ?

I suspect that the test supposedly will exit after it performs
enough abusive Fibonacci loops.

Perl configuration

$ /usr/local/bin/perl -V
Summary of my perl5 (revision 5 version 36 subversion 0) configuration:
   
  Platform:
    osname=solaris
    osvers=2.10
    archname=sun4-solaris-64-ld
    uname='sunos pollux 5.10 generic_150400-44 sun4u sparc sunw,ultraax-i2 '
    config_args='-Dcc=/opt/solarisstudio12.4/bin/c99 -Dprefix=/usr/local -Dmksymlinks -Accflags=-Xc -g -xO0 -errfmt=error -erroff=%none -xmemalign=8s -errshort=full -xstrconst -xildoff -m64 -xnolibmil -xcode=pic32 -xregs=no%appl -xlibmieee -ftrap=%none -xchip=ultra -mc -xs -xbuiltin=%none -xdebugformat=dwarf -xunroll=1 -L/usr/local/lib -R/usr/local/lib -I/usr/local/include -D_XOPEN_SOURCE=600 -D__EXTENSIONS__'
    hint=recommended
    useposix=true
    d_sigaction=define
    useithreads=undef
    usemultiplicity=undef
    use64bitint=define
    use64bitall=define
    uselongdouble=define
    usemymalloc=n
    default_inc_excludes_dot=define
  Compiler:
    cc='/opt/solarisstudio12.4/bin/c99'
    ccflags ='-Xc -g -xO0 -errfmt=error -erroff=%none -xmemalign=8s -errshort=full -xstrconst -xildoff -m64 -xnolibmil -xcode=pic32 -xregs=no%appl -xlibmieee -ftrap=%none -xchip=ultra -mc -xs -xbuiltin=%none -xdebugformat=dwarf -xunroll=1 -L/usr/local/lib -R/usr/local/lib -I/usr/local/include -D_XOPEN_SOURCE=600 -D__EXTENSIONS__ -I/usr/local/include -m64 -D_LARGEFILE_SOURCE -D_FILE_OFFSET_BITS=64 -DPERL_USE_SAFE_PUTENV'
    optimize='-g -O0 -xcode=pic32'
    cppflags='-Xc -g -xO0 -errfmt=error -erroff=%none -xmemalign=8s -errshort=full -xstrconst -xildoff -m64 -xnolibmil -xcode=pic32 -xregs=no%appl -xlibmieee -ftrap=%none -xchip=ultra -mc -xs -xbuiltin=%none -xdebugformat=dwarf -xunroll=1 -L/usr/local/lib -R/usr/local/lib -I/usr/local/include -D_XOPEN_SOURCE=600 -D__EXTENSIONS__ -I/usr/local/include'
    ccversion='Sun C 5.13 SunOS_sparc 2014/10/20'
    gccversion=''
    gccosandvers=''
    intsize=4
    longsize=8
    ptrsize=8
    doublesize=8
    byteorder=87654321
    doublekind=4
    d_longlong=define
    longlongsize=8
    d_longdbl=define
    longdblsize=16
    longdblkind=2
    ivtype='long'
    ivsize=8
    nvtype='long double'
    nvsize=16
    Off_t='off_t'
    lseeksize=8
    alignbytes=8
    prototype=define
  Linker and Libraries:
    ld='/opt/solarisstudio12.4/bin/c99'
    ldflags =' -L/usr/lib -L/usr/ccs/lib -L/opt/solarisstudio12.4/lib/compilers/staticlib/sparcv9 -L/opt/solarisstudio12.4/lib/compilers/sparcv9 -L/usr/xpg4/lib/64 -L/lib/64 -L/usr/local/lib -m64 '
    libpth=/usr/lib /usr/ccs/lib /opt/solarisstudio12.4/lib/compilers/staticlib/sparcv9 /opt/solarisstudio12.4/lib/compilers/sparcv9 /usr/xpg4/lib/64 /lib/64 /usr/local/lib
    libs=-lpthread -lsocket -lnsl -ldl -lm -lc -lsunmath
    perllibs=-lpthread -lsocket -lnsl -ldl -lm -lc -lsunmath
    libc=/usr/lib/sparcv9/libc.so
    so=so
    useshrplib=true
    libperl=libperl.so
    gnulibc_version=''
  Dynamic Linking:
    dlsrc=dl_dlopen.xs
    dlext=so
    d_dlsymun=undef
    ccdlflags='  -R /usr/local/lib/perl5/5.36.0/sun4-solaris-64-ld/CORE'
    cccdlflags='-xcode=pic32'
    lddlflags=' -G -m64 -L/usr/lib -L/usr/ccs/lib -L/opt/solarisstudio12.4/lib/compilers/staticlib/sparcv9 -L/opt/solarisstudio12.4/lib/compilers/sparcv9 -L/usr/xpg4/lib/64 -L/lib/64 -L/usr/local/lib'


Characteristics of this binary (from libperl): 
  Compile-time options:
    HAS_TIMES
    PERLIO_LAYERS
    PERL_COPY_ON_WRITE
    PERL_DONT_CREATE_GVSV
    PERL_MALLOC_WRAP
    PERL_OP_PARENT
    PERL_PRESERVE_IVUV
    PERL_USE_SAFE_PUTENV
    USE_64_BIT_ALL
    USE_64_BIT_INT
    USE_LARGE_FILES
    USE_LOCALE
    USE_LOCALE_COLLATE
    USE_LOCALE_CTYPE
    USE_LOCALE_NUMERIC
    USE_LOCALE_TIME
    USE_LONG_DOUBLE
    USE_PERLIO
    USE_PERL_ATOF
  Built under solaris
  Compiled at Feb 18 2023 16:22:42
  %ENV:
    PERL_TEST_TIME_OUT_FACTOR="3"
  @INC:
    /usr/local/lib/perl5/site_perl/5.36.0/sun4-solaris-64-ld
    /usr/local/lib/perl5/site_perl/5.36.0
    /usr/local/lib/perl5/5.36.0/sun4-solaris-64-ld
    /usr/local/lib/perl5/5.36.0
    /usr/local/lib/perl5/site_perl/5.26.1
    /usr/local/lib/perl5/site_perl/5.26.0
    /usr/local/lib/perl5/site_perl/5.20.1
    /usr/local/lib/perl5/site_perl

Github rejects my trace data as it is too large.
Best I can do is attach a compressed txt file.

-- 
Dennis Clarke
RISC-V/SPARC/PPC/ARM/CISC
UNIX and Linux spoken
GreyBeard and suspenders optional

perl_bug_report_benchmark.txt.gz

@demerphq
Copy link
Collaborator

Please can you provide the output of:

./perl -Ilib -MBenchmark -e'Benchmark->debug(1); do "./lib/Benchmark.t"' 2>&1 | perl -lne'BEGIN{$LAST=""; $COUNT=0}; if ($LAST eq $_) { $COUNT++ } else { print "x $COUNT" if $COUNT; $COUNT=0; print $_;  $LAST = $_ }'

It should look something like this:

new=1676949703 0.13 0 0 0 0
ok 1 - 'Ensure we can create a benchmark object' isa 'Benchmark'
timeit 5 CODE(0x55925b4038d8)
runloop 5 'sub { for (1 .. 5) { local $_; package main; &$c; } }'
new=1676949703 0.13 0 0 0 0
x 83
new=1676949703 0.14 0 0 0 0
new=1676949703 0.14 0 0 0 5
runloop: 0 wallclock secs ( 0.00 usr +  0.00 sys =  0.00 CPU)
runloop 5 'sub { for (1 .. 5) { local $_; package main; &$c; } }'
new=1676949703 0.14 0 0 0 0
x 87
new=1676949703 0.15 0 0 0 0
new=1676949703 0.15 0 0 0 5
runloop: 0 wallclock secs ( 0.00 usr +  0.00 sys =  0.00 CPU)
timeit:  0 wallclock secs ( 0.00 usr +  0.00 sys =  0.00 CPU)
      -  0 wallclock secs ( 0.00 usr +  0.00 sys =  0.00 CPU)
      =  0 wallclock secs ( 0.00 usr +  0.00 sys =  0.00 CPU)
ok 2 - 'timeit CODEREF' isa 'Benchmark'
ok 3 - benchmarked code was run 5 times

For now we do not need any truss output or anything like that. Thanks.

@demerphq
Copy link
Collaborator

Oh, also, please feel free to kill it after 20 seconds. If it takes any longer than that something is wrong and letting it run longer wont help us debug it.

@demerphq demerphq self-assigned this Feb 21, 2023
@blastwave
Copy link
Author


I am looking at the command line you posted : 

./perl -Ilib -MBenchmark -e'Benchmark->debug(1); do "./lib/Benchmark.t"' 2>&1 | perl -lne'BEGIN{$LAST=""; $COUNT=0}; if ($LAST eq $_) { $COUNT++ } else { print "x $COUNT" if $COUNT; $COUNT=0; print $_;  $LAST = $_ }'

I still have PERL_TEST_TIME_OUT_FACTOR=3 in my environment.

I will guess that the perl in the do loop is actually supposed to be "./perl"  and I let
it flail for a good full minute but I never ever did see anything like "wallclock" :   

pollux $ 
pollux $ date -u   
Tue Feb 21 08:25:01 GMT 2023
pollux $ ./perl -Ilib -MBenchmark -e'Benchmark->debug(1); do "./lib/Benchmark.t"' 2>&1 | ./perl -lne'BEGIN{$LAST=""; $COUNT=0}; if ($LAST eq $_) { $COUNT++ } else { print "x $COUNT" if $COUNT; $COUNT=0; print $_;  $LAST = $_ }'
new=1676967907 0 0 0 0 0
ok 1 - 'Ensure we can create a benchmark object' isa 'Benchmark'
timeit 5 CODE(0x100871450)
runloop 5 'sub { for (1 .. 5) { local $_; package main; &$c; } }'
new=1676967907 0 0 0 0 0
x 92
new=1676967908 0 0 0 0 0
x 8
new=1676967909 0 0 0 0 0
x 4
new=1676967910 0 0 0 0 0
x 3
new=1676967911 0 0 0 0 0
x 1
new=1676967912 0 0 0 0 0
x 1
new=1676967913 0 0 0 0 0
x 1
new=1676967914 0 0 0 0 0
new=1676967915 0 0 0 0 0
x 1
new=1676967916 0 0 0 0 0
new=1676967917 0 0 0 0 0
new=1676967918 0 0 0 0 0
new=1676967920 0 0 0 0 0
new=1676967921 0 0 0 0 0
new=1676967923 0 0 0 0 0
new=1676967924 0 0 0 0 0
new=1676967926 0 0 0 0 0
new=1676967928 0 0 0 0 0
new=1676967930 0 0 0 0 0
new=1676967932 0 0 0 0 0
new=1676967934 0 0 0 0 0
new=1676967937 0 0 0 0 0
new=1676967940 0 0 0 0 0
new=1676967943 0 0 0 0 0
new=1676967947 0 0 0 0 0
new=1676967951 0 0 0 0 0
new=1676967955 0 0 0 0 0
new=1676967960 0 0 0 0 0
^Cpollux $ date -u
Tue Feb 21 08:26:02 GMT 2023
pollux $ 

Hope that helps.

@demerphq
Copy link
Collaborator

As far as I can tell the times() function is broken on your build. I do not know why.

Try this program please:

$ ./perl -le'for (1..5) { print join ", ", times; my $t=time+1; $x= 0; while (time<$t) { $x+=sqrt(time) }  }'
0, 0, 0, 0
0.09, 0, 0, 0
1.09, 0, 0, 0
2.08, 0, 0, 0
3.07, 0, 0, 0

I expect you will see all zeros. I am not sure how Configure probes for times(), maybe @Tux or @tonycoz know.

We can probably modify Benchmark.t to detect that times is broken and not run to the heat death of the universe (or more likely the heat death of your CPU :-)

But really we should just fix whatever it is that has broken times. You said it works fine with an older perl?

@demerphq
Copy link
Collaborator

Ah, i found it. it is related to HAS_TIMES which you appear to have judging by your -V output.

The code is this:

PP(pp_tms)
{
#ifdef HAS_TIMES
    dSP;
    struct tms timesbuf;

    EXTEND(SP, 4);
    (void)PerlProc_times(&timesbuf);

    mPUSHn(((NV)timesbuf.tms_utime)/(NV)PL_clocktick);
    if (GIMME_V == G_LIST) {
        mPUSHn(((NV)timesbuf.tms_stime)/(NV)PL_clocktick);
        mPUSHn(((NV)timesbuf.tms_cutime)/(NV)PL_clocktick);
        mPUSHn(((NV)timesbuf.tms_cstime)/(NV)PL_clocktick);
    }
    RETURN;

(there is more but the rest is not for builds where HAS_TIMES is true).

Some additional data:

    /* Use sysconf(_SC_CLK_TCK) if available, if not
     * available or if the sysconf() fails, use the HZ.
     * The HZ if not originally defined has been by now
     * been defined as CLK_TCK, if available. */
#if defined(HAS_SYSCONF) && defined(_SC_CLK_TCK)
    PL_clocktick = sysconf(_SC_CLK_TCK);
    if (PL_clocktick <= 0)
#endif
         PL_clocktick = HZ;

Im not sure the next steps to debug this. Maybe write a small C program that uses times() (man times on your box for details) and does the equivalent test?

@tonycoz
Copy link
Contributor

tonycoz commented Feb 21, 2023

I am not sure how Configure probes for times(), maybe @Tux or @tonycoz know.

Configure checks that the C symbol is defined either with checking a symbol dump of libc or by trying to link a trivial program that refers to the name.

There's no sanity check for the times it returns.

@demerphq
Copy link
Collaborator

@blastwave i think you should replicate the below and let us know what you get.

$ cat test_times.c
#include <sys/times.h>
#include <unistd.h>
#include <time.h>
#include <math.h>
#include <stdio.h>

int main(int argv, char **argc) {
    long clocktick = sysconf(_SC_CLK_TCK);
    printf("clocktick = %ld\n", clocktick);
    for(int i = 0 ; i < 3 ; i++) {
        time_t t1 = time(NULL);
        time_t t2;
        double x = 0.0;
        do {
            t2 = time(NULL);
            x += sqrt((double)t2);
        } while (t2 <= t1);
        struct tms got_tms;
        clock_t res = times(&got_tms);
        printf("%10ld | %10ld %10ld %10ld %10ld\n",
                res,
                got_tms.tms_utime,  /* user time */
                got_tms.tms_stime,  /* system time */
                got_tms.tms_cutime, /* user time of children */
                got_tms.tms_cstime); /* system time of children */
        printf("%10ld | %10ld %10ld %10ld %10ld (scaled)\n",
                res/clocktick,
                got_tms.tms_utime/clocktick,  /* user time */
                got_tms.tms_stime/clocktick,  /* system time */
                got_tms.tms_cutime/clocktick, /* user time of children */
                got_tms.tms_cstime/clocktick); /* system time of children */
    }
}
$ gcc test_times.c -o test_times -lm
$ ./test_times
clocktick = 100
1743595356 |         79          0          0          0
  17435953 |          0          0          0          0 (scaled)
1743595456 |        179          0          0          0
  17435954 |          1          0          0          0 (scaled)
1743595556 |        279          0          0          0
  17435955 |          2          0          0          0 (scaled)

demerphq added a commit that referenced this issue Feb 22, 2023
If time() or times() is broken then Benchmark can infinite loop.
This adds a sanity check that will die early if it appears that
either are broken.

This fixes the infinite loop part of GH Issue #20839
demerphq added a commit that referenced this issue Feb 22, 2023
If time() or times() is broken then Benchmark can infinite loop.
This adds a sanity check that will die early if it appears that
either are broken.

This fixes the infinite loop part of GH Issue #20839
@demerphq
Copy link
Collaborator

demerphq commented Feb 22, 2023

@blastwave can you please try building and testing the branch: yves/benchmark_times_sanity_check

eg,

git fetch
git checkout yves/benchmark_times_sanity_check
make -j16
./perl -Ilib lib/Benchmark.t

thanks.

demerphq added a commit that referenced this issue Feb 22, 2023
If time() or times() is broken then Benchmark can infinite loop.
This adds a sanity check that will die early if it appears that
either are broken.

This fixes the infinite loop part of GH Issue #20839
@blastwave
Copy link
Author

I am just catching up on this now. 

I did : 

pollux $ 
pollux $ cat do_times.c

#include <sys/times.h>
#include <unistd.h>
#include <time.h>
#include <math.h>
#include <stdio.h>

int main(int argv, char **argc) 
{
    long clocktick = sysconf(_SC_CLK_TCK);
    printf("clocktick = %ld\n", clocktick);
    for (int i = 0 ; i < 3 ; i++) {
        time_t t1 = time(NULL);
        time_t t2;
        double x = 0.0;
        do {
            t2 = time(NULL);
            x += sqrt((double)t2);
        } while (t2 <= t1);
        struct tms got_tms;
        clock_t res = times(&got_tms);

        printf("%10ld | %10ld %10ld %10ld %10ld\n",
            res, got_tms.tms_utime,  /* user time */
            got_tms.tms_stime,  /* system time */
            got_tms.tms_cutime, /* user time of children */
            got_tms.tms_cstime); /* system time of children */

        printf("%10ld | %10ld %10ld %10ld %10ld (scaled)\n",
            res / clocktick,
            got_tms.tms_utime / clocktick,  /* user time */
            got_tms.tms_stime / clocktick,  /* system time */
            got_tms.tms_cutime / clocktick, /* user time of children */
            got_tms.tms_cstime / clocktick); /* system time of children */

    }
}

pollux $ 
pollux $ $CC $CFLAGS $CPPFLAGS -o do_times do_times.c -lm
pollux $ 
pollux $ ./do_times
clocktick = 100
  37696209 |          0          0          0          0
    376962 |          0          0          0          0 (scaled)
  37696309 |          0          0          0          0
    376963 |          0          0          0          0 (scaled)
  37696409 |          0          0          0          0
    376964 |          0          0          0          0 (scaled)
pollux $ 

@blastwave
Copy link
Author

Sorry I can not git anything on that machine. There is no git there. Yet.
I am still trying to build it. However first I need Perl and then OpenSSL and then
libSSH and then libCurl and then ... etc etc and I know this process well.

@demerphq
Copy link
Collaborator

So that confirms it, your system times() is broken. I think you need to take this up with someone else, it's not a bug in perl itself. I don't know who tho. You should be able to install perl ok, but anything that relies on times() will be broken until you get to the bottom of it.

demerphq added a commit that referenced this issue Feb 22, 2023
If time() or times() is broken then Benchmark can infinite loop.
This adds a sanity check that will die early if it appears that
either are broken.

This fixes the infinite loop part of GH Issue #20839
demerphq added a commit that referenced this issue Feb 22, 2023
If time() or times() is broken then Benchmark can infinite loop.
This adds a sanity check that will die early if it appears that
either are broken.

This fixes the infinite loop part of GH Issue #20839
demerphq added a commit that referenced this issue Feb 23, 2023
If time() or times() is broken then Benchmark can infinite loop.
This adds a sanity check that will die early if it appears that
either are broken.

This fixes the infinite loop part of GH Issue #20839
@demerphq
Copy link
Collaborator

I'm closing this. The part that we can fix is fixed.

pjacklam pushed a commit to pjacklam/perl5 that referenced this issue May 20, 2023
If time() or times() is broken then Benchmark can infinite loop.
This adds a sanity check that will die early if it appears that
either are broken.

This fixes the infinite loop part of GH Issue Perl#20839
pjacklam pushed a commit to pjacklam/perl5 that referenced this issue May 20, 2023
If time() or times() is broken then Benchmark can infinite loop.
This adds a sanity check that will die early if it appears that
either are broken.

This fixes the infinite loop part of GH Issue Perl#20839
khwilliamson pushed a commit to khwilliamson/perl5 that referenced this issue Jul 10, 2023
If time() or times() is broken then Benchmark can infinite loop.
This adds a sanity check that will die early if it appears that
either are broken.

This fixes the infinite loop part of GH Issue Perl#20839
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

3 participants