search

timbunce / devel-nytprof

Devel::NYTProf is a powerful feature-rich source code profiler for Perl. (Mostly in maintenance mode, so PRs are much more likely to be acted upon than Issues.)
http://blog.timbunce.org/tag/nytprof/
67 stars 51 forks source link

t/test62-subcaller1.t fails on older perls on Windows #153

Open jkeenan opened 3 years ago

jkeenan commented 3 years ago

CPANtesters reports indicate that what, before Devel-NYTProf-6.07, was t/test62-subcaller1.t (and what is now t/test62-subcaller1-a.t) can experience test failures on older versions of Strawberry Perl. Here is output from a report generated on a Strawberry Perl 5.14.4 with NYTProf version 6.06.

t/test61-submerge.t .... ok

#   Failed test 'test62-subcaller1.rdt match generated profile data for blocks=1 calls=1 compress=0 leave=1 savesrc=1 slowops=2 start=init use_db_sub=0'
#   at t/lib/NYTProfTest.pm line 464.
#     Structures begin differing at:
#          $got->[55] = 'fid_fileinfo   3   [ C:/home/heaven/perl5/lib/perl5/Exporter.pm   3 2 0 0 ]'
#     $expected->[55] = 'fid_fileinfo   3   [ Exporter.pm   3 2 0 0 ]'

#   Failed test 'test62-subcaller1.rdt match generated profile data for blocks=1 calls=1 compress=1 leave=0 savesrc=0 slowops=2 start=init use_db_sub=0'
#   at t/lib/NYTProfTest.pm line 464.
#     Structures begin differing at:
#          $got->[55] = 'fid_fileinfo   3   [ C:/home/heaven/perl5/lib/perl5/Exporter.pm   3 2 0 0 ]'
#     $expected->[55] = 'fid_fileinfo   3   [ Exporter.pm   3 2 0 0 ]'

#   Failed test 'test62-subcaller1.rdt match generated profile data for blocks=1 calls=2 compress=1 leave=1 savesrc=1 slowops=2 start=init use_db_sub=1'
#   at t/lib/NYTProfTest.pm line 464.
#     Structures begin differing at:
#          $got->[55] = 'fid_fileinfo   3   [ C:/home/heaven/perl5/lib/perl5/Exporter.pm   3 2 0 0 ]'
#     $expected->[55] = 'fid_fileinfo   3   [ Exporter.pm   3 2 0 0 ]'

#   Failed test 'test62-subcaller1.rdt match generated profile data for blocks=1 calls=1 compress=0 leave=0 savesrc=1 slowops=2 start=init use_db_sub=0'
#   at t/lib/NYTProfTest.pm line 464.
#     Structures begin differing at:
#          $got->[55] = 'fid_fileinfo   3   [ C:/home/heaven/perl5/lib/perl5/Exporter.pm   3 2 0 0 ]'
#     $expected->[55] = 'fid_fileinfo   3   [ Exporter.pm   3 2 0 0 ]'

#   Failed test 'test62-subcaller1.rdt match generated profile data for blocks=1 calls=0 compress=0 leave=0 savesrc=0 slowops=2 start=init use_db_sub=1'
#   at t/lib/NYTProfTest.pm line 464.
#     Structures begin differing at:
#          $got->[55] = 'fid_fileinfo   3   [ C:/home/heaven/perl5/lib/perl5/Exporter.pm   3 2 0 0 ]'
#     $expected->[55] = 'fid_fileinfo   3   [ Exporter.pm   3 2 0 0 ]'

#   Failed test 'test62-subcaller1.rdt match generated profile data for blocks=1 calls=1 compress=1 leave=1 savesrc=0 slowops=2 start=init use_db_sub=1'
#   at t/lib/NYTProfTest.pm line 464.
#     Structures begin differing at:
#          $got->[55] = 'fid_fileinfo   3   [ C:/home/heaven/perl5/lib/perl5/Exporter.pm   3 2 0 0 ]'
#     $expected->[55] = 'fid_fileinfo   3   [ Exporter.pm   3 2 0 0 ]'

#   Failed test 'test62-subcaller1.rdt match generated profile data for blocks=1 calls=1 compress=1 leave=1 savesrc=0 slowops=2 start=init use_db_sub=0'
#   at t/lib/NYTProfTest.pm line 464.
#     Structures begin differing at:
#          $got->[55] = 'fid_fileinfo   3   [ C:/home/heaven/perl5/lib/perl5/Exporter.pm   3 2 0 0 ]'
#     $expected->[55] = 'fid_fileinfo   3   [ Exporter.pm   3 2 0 0 ]'

#   Failed test 'test62-subcaller1.rdt match generated profile data for blocks=1 calls=1 compress=0 leave=1 savesrc=1 slowops=2 start=init use_db_sub=1'
#   at t/lib/NYTProfTest.pm line 464.
#     Structures begin differing at:
#          $got->[55] = 'fid_fileinfo   3   [ C:/home/heaven/perl5/lib/perl5/Exporter.pm   3 2 0 0 ]'
#     $expected->[55] = 'fid_fileinfo   3   [ Exporter.pm   3 2 0 0 ]'

#   Failed test 'test62-subcaller1.rdt match generated profile data for blocks=1 calls=0 compress=0 leave=1 savesrc=0 slowops=2 start=init use_db_sub=1'
#   at t/lib/NYTProfTest.pm line 464.
#     Structures begin differing at:
#          $got->[55] = 'fid_fileinfo   3   [ C:/home/heaven/perl5/lib/perl5/Exporter.pm   3 2 0 0 ]'
#     $expected->[55] = 'fid_fileinfo   3   [ Exporter.pm   3 2 0 0 ]'

#   Failed test 'test62-subcaller1.rdt match generated profile data for blocks=1 calls=2 compress=1 leave=0 savesrc=1 slowops=2 start=init use_db_sub=0'
#   at t/lib/NYTProfTest.pm line 464.
#     Structures begin differing at:
#          $got->[55] = 'fid_fileinfo   3   [ C:/home/heaven/perl5/lib/perl5/Exporter.pm   3 2 0 0 ]'
#     $expected->[55] = 'fid_fileinfo   3   [ Exporter.pm   3 2 0 0 ]'

#   Failed test 'test62-subcaller1.rdt match generated profile data for blocks=1 calls=1 compress=1 leave=0 savesrc=0 slowops=2 start=init use_db_sub=1'
#   at t/lib/NYTProfTest.pm line 464.
#     Structures begin differing at:
#          $got->[55] = 'fid_fileinfo   3   [ C:/home/heaven/perl5/lib/perl5/Exporter.pm   3 2 0 0 ]'
#     $expected->[55] = 'fid_fileinfo   3   [ Exporter.pm   3 2 0 0 ]'

#   Failed test 'test62-subcaller1.rdt match generated profile data for blocks=1 calls=2 compress=1 leave=0 savesrc=1 slowops=2 start=init use_db_sub=1'
#   at t/lib/NYTProfTest.pm line 464.
#     Structures begin differing at:
#          $got->[55] = 'fid_fileinfo   3   [ C:/home/heaven/perl5/lib/perl5/Exporter.pm   3 2 0 0 ]'
#     $expected->[55] = 'fid_fileinfo   3   [ Exporter.pm   3 2 0 0 ]'

#   Failed test 'test62-subcaller1.rdt match generated profile data for blocks=1 calls=0 compress=0 leave=0 savesrc=0 slowops=2 start=init use_db_sub=0'
#   at t/lib/NYTProfTest.pm line 464.
#     Structures begin differing at:
#          $got->[55] = 'fid_fileinfo   3   [ C:/home/heaven/perl5/lib/perl5/Exporter.pm   3 2 0 0 ]'
#     $expected->[55] = 'fid_fileinfo   3   [ Exporter.pm   3 2 0 0 ]'

#   Failed test 'test62-subcaller1.rdt match generated profile data for blocks=1 calls=0 compress=0 leave=1 savesrc=0 slowops=2 start=init use_db_sub=0'
#   at t/lib/NYTProfTest.pm line 464.
#     Structures begin differing at:
#          $got->[55] = 'fid_fileinfo   3   [ C:/home/heaven/perl5/lib/perl5/Exporter.pm   3 2 0 0 ]'
#     $expected->[55] = 'fid_fileinfo   3   [ Exporter.pm   3 2 0 0 ]'

#   Failed test 'test62-subcaller1.rdt match generated profile data for blocks=1 calls=1 compress=0 leave=0 savesrc=1 slowops=2 start=init use_db_sub=1'
#   at t/lib/NYTProfTest.pm line 464.
#     Structures begin differing at:
#          $got->[55] = 'fid_fileinfo   3   [ C:/home/heaven/perl5/lib/perl5/Exporter.pm   3 2 0 0 ]'
#     $expected->[55] = 'fid_fileinfo   3   [ Exporter.pm   3 2 0 0 ]'

#   Failed test 'test62-subcaller1.rdt match generated profile data for blocks=1 calls=2 compress=1 leave=1 savesrc=1 slowops=2 start=init use_db_sub=0'
#   at t/lib/NYTProfTest.pm line 464.
#     Structures begin differing at:
#          $got->[55] = 'fid_fileinfo   3   [ C:/home/heaven/perl5/lib/perl5/Exporter.pm   3 2 0 0 ]'
#     $expected->[55] = 'fid_fileinfo   3   [ Exporter.pm   3 2 0 0 ]'
# SUMMARY: Breakdown of test62-subcaller1 test failures by option settings:
#           calls: 0 => {FAIL 4}, 1 => {FAIL 8}, 2 => {FAIL 4}
# FAILED with blocks=1:calls=0:compress=0:file=nytprof_test62-subcaller1.out:leave=0:savesrc=0:slowops=2:start=init:use_db_sub=0
# FAILED with blocks=1:calls=0:compress=0:file=nytprof_test62-subcaller1.out:leave=0:savesrc=0:slowops=2:start=init:use_db_sub=1
# FAILED with blocks=1:calls=0:compress=0:file=nytprof_test62-subcaller1.out:leave=1:savesrc=0:slowops=2:start=init:use_db_sub=0
# FAILED with blocks=1:calls=0:compress=0:file=nytprof_test62-subcaller1.out:leave=1:savesrc=0:slowops=2:start=init:use_db_sub=1
# FAILED with blocks=1:calls=1:compress=0:file=nytprof_test62-subcaller1.out:leave=0:savesrc=1:slowops=2:start=init:use_db_sub=0
# FAILED with blocks=1:calls=1:compress=0:file=nytprof_test62-subcaller1.out:leave=0:savesrc=1:slowops=2:start=init:use_db_sub=1
# FAILED with blocks=1:calls=1:compress=0:file=nytprof_test62-subcaller1.out:leave=1:savesrc=1:slowops=2:start=init:use_db_sub=0
# FAILED with blocks=1:calls=1:compress=0:file=nytprof_test62-subcaller1.out:leave=1:savesrc=1:slowops=2:start=init:use_db_sub=1
# FAILED with blocks=1:calls=1:compress=1:file=nytprof_test62-subcaller1.out:leave=0:savesrc=0:slowops=2:start=init:use_db_sub=0
# FAILED with blocks=1:calls=1:compress=1:file=nytprof_test62-subcaller1.out:leave=0:savesrc=0:slowops=2:start=init:use_db_sub=1
# FAILED with blocks=1:calls=1:compress=1:file=nytprof_test62-subcaller1.out:leave=1:savesrc=0:slowops=2:start=init:use_db_sub=0
# FAILED with blocks=1:calls=1:compress=1:file=nytprof_test62-subcaller1.out:leave=1:savesrc=0:slowops=2:start=init:use_db_sub=1
# FAILED with blocks=1:calls=2:compress=1:file=nytprof_test62-subcaller1.out:leave=0:savesrc=1:slowops=2:start=init:use_db_sub=0
# FAILED with blocks=1:calls=2:compress=1:file=nytprof_test62-subcaller1.out:leave=0:savesrc=1:slowops=2:start=init:use_db_sub=1
# FAILED with blocks=1:calls=2:compress=1:file=nytprof_test62-subcaller1.out:leave=1:savesrc=1:slowops=2:start=init:use_db_sub=0
# FAILED with blocks=1:calls=2:compress=1:file=nytprof_test62-subcaller1.out:leave=1:savesrc=1:slowops=2:start=init:use_db_sub=1
# Looks like you failed 16 tests of 65.
t/test62-subcaller1.t .. 
Dubious, test returned 16 (wstat 4096, 0x1000)
Failed 16/65 subtests

These error reports all appear to be emanating from a single CPANtester installation which first began generating reports when NYTProf was at version 6.05. Reports emanating from the same reporter start to PASS with perl-5.20.3.

The CPANtester has not provided a name, so it will be difficult to follow up on these reports. Other CPANtesters on Windows are reporting PASSes.

xileF1337 commented 1 year ago

Hi @jkeenan,

I am currently preparing a CondaForge package recipe for Devel::NYTProf and also get failures with test 62 (t/test62-subcaller1-a.t) in the (dockerized) build environment of CondaForge's CI pipeline. This is version 6.11 of Devel::NYTProf and Perl v5.32.1. When testing with my system Perl (v5.34.1), t/test62-subcaller1-a.t is skipped and the b variant is run instead (it passes). This is the relevant output, containing some more info about package versions and env variables:

Reloading output folder: /home/conda/staged-recipes/build_artifacts
file:///home/conda/staged-recipes/build_artifact..   1.2kB @  11.8MB/s  0.0s
file:///home/conda/staged-recipes/build_artifact.. @   2.4MB/s  0.2s
Transaction

  Prefix: /opt/conda

  Updating specs:

   - perl[version='>=5.32.1,<5.33.0a0',build=*_perl5]
   - perl-text-diff
   - libgcc-ng[version='>=12']
   - perl-test-differences=0.69

  Package                  Version  Build             Channel                                                   Size
──────────────────────────────────────────────────────────────────────────────────────────────────────────────────────
  Install:
──────────────────────────────────────────────────────────────────────────────────────────────────────────────────────

  + _libgcc_mutex              0.1  conda_forge       conda-forge/linux-64                                    Cached
  + _openmp_mutex              4.5  2_gnu             conda-forge/linux-64                                    Cached
  + libgcc-ng               12.2.0  h65d4601_19       conda-forge/linux-64                                    Cached
  + libgomp                 12.2.0  h65d4601_19       conda-forge/linux-64                                    Cached
  + libnsl                   2.0.0  h7f98852_0        conda-forge/linux-64                                    Cached
  + perl                    5.32.1  2_h7f98852_perl5  conda-forge/linux-64                                    Cached
  + perl-algorithm-diff      1.201  pl5321hd8ed1ab_0  conda-forge/noarch                                      Cached
  + perl-test-differences     0.69  pl5321ha770c72_0  /home/conda/staged-recipes/build_artifacts/linux-64     Cached
  + perl-text-diff            1.45  pl5321hd8ed1ab_0  conda-forge/noarch                                      Cached

  Summary:

  Install: 9 packages

  Total download: 0 B

──────────────────────────────────────────────────────────────────────────────────────────────────────────────────────

## Package Plan ##

  environment location: /home/conda/staged-recipes/build_artifacts/perl-devel-nytprof_1666788111982/_build_env

The following NEW packages will be INSTALLED:

    _libgcc_mutex:           0.1-conda_forge    conda-forge
    _openmp_mutex:           4.5-2_gnu          conda-forge
    binutils_impl_linux-64:  2.39-h6ceecb4_0    conda-forge
    binutils_linux-64:       2.39-h5fc0e48_11   conda-forge
    gcc_impl_linux-64:       10.4.0-h5231bdf_19 conda-forge
    gcc_linux-64:            10.4.0-h9215b83_11 conda-forge
    kernel-headers_linux-64: 2.6.32-he073ed8_15 conda-forge
    ld_impl_linux-64:        2.39-hc81fddc_0    conda-forge
    libgcc-devel_linux-64:   10.4.0-hd38fd1e_19 conda-forge
    libgcc-ng:               12.2.0-h65d4601_19 conda-forge
    libgomp:                 12.2.0-h65d4601_19 conda-forge
    libsanitizer:            10.4.0-h5246dfb_19 conda-forge
    libstdcxx-ng:            12.2.0-h46fd767_19 conda-forge
    make:                    4.3-hd18ef5c_1     conda-forge
    sysroot_linux-64:        2.12-he073ed8_15   conda-forge

Preparing transaction: ...working... done
Verifying transaction: ...working... done
Executing transaction: ...working... done
Found source in cache: Devel-NYTProf-6.11_bb1eb2065a.tar.gz
INFO:conda_build.source:Found source in cache: Devel-NYTProf-6.11_bb1eb2065a.tar.gz
Extracting download
source tree in: /home/conda/staged-recipes/build_artifacts/perl-devel-nytprof_1666788111982/work
export PREFIX=/home/conda/staged-recipes/build_artifacts/perl-devel-nytprof_1666788111982/_h_env_placehold_placehold_placehold_placehold_placehold_placehold_placehold_placehold_placehold_placehold_placehold_placehold_placehold_placehold_placehold_placehold_placehold_pl
export BUILD_PREFIX=/home/conda/staged-recipes/build_artifacts/perl-devel-nytprof_1666788111982/_build_env
export SRC_DIR=/home/conda/staged-recipes/build_artifacts/perl-devel-nytprof_1666788111982/work
INFO: activate-binutils_linux-64.sh made the following environmental changes:
+ADDR2LINE=$BUILD_PREFIX/bin/x86_64-conda-linux-gnu-addr2line
+AR=$BUILD_PREFIX/bin/x86_64-conda-linux-gnu-ar
+AS=$BUILD_PREFIX/bin/x86_64-conda-linux-gnu-as
+CXXFILT=$BUILD_PREFIX/bin/x86_64-conda-linux-gnu-c++filt
+ELFEDIT=$BUILD_PREFIX/bin/x86_64-conda-linux-gnu-elfedit
+GPROF=$BUILD_PREFIX/bin/x86_64-conda-linux-gnu-gprof
+LD_GOLD=$BUILD_PREFIX/bin/x86_64-conda-linux-gnu-ld.gold
+LD=$BUILD_PREFIX/bin/x86_64-conda-linux-gnu-ld
+NM=$BUILD_PREFIX/bin/x86_64-conda-linux-gnu-nm
+OBJCOPY=$BUILD_PREFIX/bin/x86_64-conda-linux-gnu-objcopy
+OBJDUMP=$BUILD_PREFIX/bin/x86_64-conda-linux-gnu-objdump
+RANLIB=$BUILD_PREFIX/bin/x86_64-conda-linux-gnu-ranlib
+READELF=$BUILD_PREFIX/bin/x86_64-conda-linux-gnu-readelf
+SIZE=$BUILD_PREFIX/bin/x86_64-conda-linux-gnu-size
+STRINGS=$BUILD_PREFIX/bin/x86_64-conda-linux-gnu-strings
+STRIP=$BUILD_PREFIX/bin/x86_64-conda-linux-gnu-strip
INFO: activate-gcc_linux-64.sh made the following environmental changes:
+build_alias=x86_64-conda-linux-gnu
-BUILD=x86_64-conda_cos6-linux-gnu
+BUILD=x86_64-conda-linux-gnu
+CC_FOR_BUILD=$BUILD_PREFIX/bin/x86_64-conda-linux-gnu-cc
+CC=$BUILD_PREFIX/bin/x86_64-conda-linux-gnu-cc
+CFLAGS=-march=nocona -mtune=haswell -ftree-vectorize -fPIC -fstack-protector-strong -fno-plt -O2 -ffunction-sections -pipe -isystem $PREFIX/include -fdebug-prefix-map=$SRC_DIR=/usr/local/src/conda/perl-devel-nytprof-6.11 -fdebug-prefix-map=$PREFIX=/usr/local/src/conda-prefix
+CMAKE_ARGS=-DCMAKE_AR=$BUILD_PREFIX/bin/x86_64-conda-linux-gnu-ar -DCMAKE_CXX_COMPILER_AR=$BUILD_PREFIX/bin/x86_64-conda-linux-gnu-gcc-ar -DCMAKE_C_COMPILER_AR=$BUILD_PREFIX/bin/x86_64-conda-linux-gnu-gcc-ar -DCMAKE_RANLIB=$BUILD_PREFIX/bin/x86_64-conda-linux-gnu-ranlib -DCMAKE_CXX_COMPILER_RANLIB=$BUILD_PREFIX/bin/x86_64-conda-linux-gnu-gcc-ranlib -DCMAKE_C_COMPILER_RANLIB=$BUILD_PREFIX/bin/x86_64-conda-linux-gnu-gcc-ranlib -DCMAKE_LINKER=$BUILD_PREFIX/bin/x86_64-conda-linux-gnu-ld -DCMAKE_STRIP=$BUILD_PREFIX/bin/x86_64-conda-linux-gnu-strip -DCMAKE_FIND_ROOT_PATH_MODE_PROGRAM=NEVER -DCMAKE_FIND_ROOT_PATH_MODE_LIBRARY=ONLY -DCMAKE_FIND_ROOT_PATH_MODE_INCLUDE=ONLY -DCMAKE_FIND_ROOT_PATH=$PREFIX;$BUILD_PREFIX/x86_64-conda-linux-gnu/sysroot -DCMAKE_INSTALL_PREFIX=$PREFIX -DCMAKE_INSTALL_LIBDIR=lib -DCMAKE_PROGRAM_PATH=$BUILD_PREFIX/bin;$PREFIX/bin
+CMAKE_PREFIX_PATH=$PREFIX:$BUILD_PREFIX/x86_64-conda-linux-gnu/sysroot/usr
+CONDA_BUILD_SYSROOT=$BUILD_PREFIX/x86_64-conda-linux-gnu/sysroot
+_CONDA_PYTHON_SYSCONFIGDATA_NAME=_sysconfigdata_x86_64_conda_cos6_linux_gnu
+CONDA_TOOLCHAIN_BUILD=x86_64-conda-linux-gnu
+CONDA_TOOLCHAIN_HOST=x86_64-conda-linux-gnu
+CPPFLAGS=-DNDEBUG -D_FORTIFY_SOURCE=2 -O2 -isystem $PREFIX/include
+CPP=$BUILD_PREFIX/bin/x86_64-conda-linux-gnu-cpp
+DEBUG_CFLAGS=-march=nocona -mtune=haswell -ftree-vectorize -fPIC -fstack-protector-all -fno-plt -Og -g -Wall -Wextra -fvar-tracking-assignments -ffunction-sections -pipe -isystem $PREFIX/include -fdebug-prefix-map=$SRC_DIR=/usr/local/src/conda/perl-devel-nytprof-6.11 -fdebug-prefix-map=$PREFIX=/usr/local/src/conda-prefix
+DEBUG_CPPFLAGS=-D_DEBUG -D_FORTIFY_SOURCE=2 -Og -isystem $PREFIX/include
+GCC_AR=$BUILD_PREFIX/bin/x86_64-conda-linux-gnu-gcc-ar
+GCC=$BUILD_PREFIX/bin/x86_64-conda-linux-gnu-gcc
+GCC_NM=$BUILD_PREFIX/bin/x86_64-conda-linux-gnu-gcc-nm
+GCC_RANLIB=$BUILD_PREFIX/bin/x86_64-conda-linux-gnu-gcc-ranlib
+host_alias=x86_64-conda-linux-gnu
+HOST=x86_64-conda-linux-gnu
+LDFLAGS=-Wl,-O2 -Wl,--sort-common -Wl,--as-needed -Wl,-z,relro -Wl,-z,now -Wl,--disable-new-dtags -Wl,--gc-sections -Wl,--allow-shlib-undefined -Wl,-rpath,$PREFIX/lib -Wl,-rpath-link,$PREFIX/lib -L$PREFIX/lib
Looking for header files and functions...
Your perl was compiled with gcc (version 9.4.0), okay.
Checking if your kit is complete...
Looks good
Generating a Unix-style Makefile
Writing Makefile for Devel::NYTProf
Writing MYMETA.yml and MYMETA.json
cp lib/Devel/NYTProf/Test.pm blib/lib/Devel/NYTProf/Test.pm
cp lib/Devel/NYTProf/Core.pm blib/lib/Devel/NYTProf/Core.pm
cp lib/Devel/NYTProf/js/jit/jit-yc.js blib/lib/Devel/NYTProf/js/jit/jit-yc.js
cp lib/Devel/NYTProf/js/style-tablesorter.css blib/lib/Devel/NYTProf/js/style-tablesorter.css
cp lib/Devel/NYTProf/ReadStream.pm blib/lib/Devel/NYTProf/ReadStream.pm
cp lib/Devel/NYTProf/js/bg.png blib/lib/Devel/NYTProf/js/bg.png
cp lib/Devel/NYTProf/FileHandle.pm blib/lib/Devel/NYTProf/FileHandle.pm
cp lib/Devel/NYTProf/js/jquery.tablesorter.min.js blib/lib/Devel/NYTProf/js/jquery.tablesorter.min.js
cp lib/Devel/NYTProf/Util.pm blib/lib/Devel/NYTProf/Util.pm
cp lib/Devel/NYTProf/SubInfo.pm blib/lib/Devel/NYTProf/SubInfo.pm
cp lib/Devel/NYTProf/js/jit/jit.js blib/lib/Devel/NYTProf/js/jit/jit.js
cp lib/Devel/NYTProf/Constants.pm blib/lib/Devel/NYTProf/Constants.pm
cp lib/Devel/NYTProf/Run.pm blib/lib/Devel/NYTProf/Run.pm
cp lib/Devel/NYTProf/js/desc.png blib/lib/Devel/NYTProf/js/desc.png
cp lib/Devel/NYTProf/Apache.pm blib/lib/Devel/NYTProf/Apache.pm
cp lib/Devel/NYTProf/js/jquery-min.js blib/lib/Devel/NYTProf/js/jquery-min.js
cp lib/Devel/NYTProf/js/jit/gradient30.png blib/lib/Devel/NYTProf/js/jit/gradient30.png
cp lib/Devel/NYTProf/js/asc.png blib/lib/Devel/NYTProf/js/asc.png
cp lib/Devel/NYTProf/Data.pm blib/lib/Devel/NYTProf/Data.pm
cp lib/Devel/NYTProf/js/jit/gradient20.png blib/lib/Devel/NYTProf/js/jit/gradient20.png
cp lib/Devel/NYTProf/FileInfo.pm blib/lib/Devel/NYTProf/FileInfo.pm
cp lib/Devel/NYTProf/js/jit/gradient.png blib/lib/Devel/NYTProf/js/jit/gradient.png
cp lib/Devel/NYTProf/js/jit/gradient40.png blib/lib/Devel/NYTProf/js/jit/gradient40.png
cp lib/Devel/NYTProf/Reader.pm blib/lib/Devel/NYTProf/Reader.pm
cp lib/Devel/NYTProf.pm blib/lib/Devel/NYTProf.pm
cp lib/Devel/NYTProf/js/jit/gradient50.png blib/lib/Devel/NYTProf/js/jit/gradient50.png
cp lib/Devel/NYTProf/js/jit/Treemap.css blib/lib/Devel/NYTProf/js/jit/Treemap.css
cp lib/Devel/NYTProf/SubCallInfo.pm blib/lib/Devel/NYTProf/SubCallInfo.pm
cp lib/Devel/NYTProf/js/jit/gradient-cushion1.png blib/lib/Devel/NYTProf/js/jit/gradient-cushion1.png
cp MemoryProfiling.pod blib/lib/Devel/MemoryProfiling.pod
Running Mkbootstrap for NYTProf ()
chmod 644 "NYTProf.bs"
"$PREFIX/bin/perl" -MExtUtils::Command::MM -e 'cp_nonempty' -- NYTProf.bs blib/arch/auto/Devel/NYTProf/NYTProf.bs 644
"$PREFIX/bin/perl" "$PREFIX/lib/perl5/core_perl/ExtUtils/xsubpp"  -typemap '$PREFIX/lib/perl5/core_perl/ExtUtils/typemap' -typemap '$SRC_DIR/typemap'  FileHandle.xs > FileHandle.xsc
mv FileHandle.xsc FileHandle.c
$BUILD_PREFIX/bin/..//bin/x86_64-conda-linux-gnu-gcc -c   -D_REENTRANT -D_GNU_SOURCE -march=nocona -mtune=haswell -ftree-vectorize -fPIC -fstack-protector-strong -fno-plt -O2 -ffunction-sections -pipe -isystem $PREFIX/include -fdebug-prefix-map=/home/conda/feedstock_root/build_artifacts/perl_1645063083032/work=/usr/local/src/conda/perl-5.32.1 -fdebug-prefix-map=$PREFIX=/usr/local/src/conda-prefix -D_REENTRANT -D_GNU_SOURCE -fwrapv -fno-strict-aliasing -pipe -fstack-protector-strong -D_LARGEFILE_SOURCE -D_FILE_OFFSET_BITS=64 -D_FORTIFY_SOURCE=2 -D_LARGEFILE_SOURCE -D_FILE_OFFSET_BITS=64 -O2   -DVERSION=\"6.11\" -DXS_VERSION=\"6.11\" -fPIC --sysroot=$BUILD_PREFIX/bin/..//x86_64-conda-linux-gnu/sysroot "-I$PREFIX/lib/perl5/5.32/core_perl/CORE"  -W -Wall -Wpointer-arith -Wbad-function-cast -Wno-comment -Wno-sign-compare -Wno-cast-qual -Wmissing-noreturn -Wno-unused-parameter FileHandle.c
"$PREFIX/bin/perl" "$PREFIX/lib/perl5/core_perl/ExtUtils/xsubpp"  -typemap '$PREFIX/lib/perl5/core_perl/ExtUtils/typemap' -typemap '$SRC_DIR/typemap'  NYTProf.xs > NYTProf.xsc
mv NYTProf.xsc NYTProf.c
$BUILD_PREFIX/bin/..//bin/x86_64-conda-linux-gnu-gcc -c   -D_REENTRANT -D_GNU_SOURCE -march=nocona -mtune=haswell -ftree-vectorize -fPIC -fstack-protector-strong -fno-plt -O2 -ffunction-sections -pipe -isystem $PREFIX/include -fdebug-prefix-map=/home/conda/feedstock_root/build_artifacts/perl_1645063083032/work=/usr/local/src/conda/perl-5.32.1 -fdebug-prefix-map=$PREFIX=/usr/local/src/conda-prefix -D_REENTRANT -D_GNU_SOURCE -fwrapv -fno-strict-aliasing -pipe -fstack-protector-strong -D_LARGEFILE_SOURCE -D_FILE_OFFSET_BITS=64 -D_FORTIFY_SOURCE=2 -D_LARGEFILE_SOURCE -D_FILE_OFFSET_BITS=64 -O2   -DVERSION=\"6.11\" -DXS_VERSION=\"6.11\" -fPIC --sysroot=$BUILD_PREFIX/bin/..//x86_64-conda-linux-gnu/sysroot "-I$PREFIX/lib/perl5/5.32/core_perl/CORE"  -W -Wall -Wpointer-arith -Wbad-function-cast -Wno-comment -Wno-sign-compare -Wno-cast-qual -Wmissing-noreturn -Wno-unused-parameter NYTProf.c
rm -f blib/arch/auto/Devel/NYTProf/NYTProf.so
$BUILD_PREFIX/bin/..//bin/x86_64-conda-linux-gnu-gcc  -shared -Wl,-O2 -Wl,--sort-common -Wl,--as-needed -Wl,-z,relro -Wl,-z,now -Wl,--disable-new-dtags -Wl,--gc-sections -Wl,--allow-shlib-undefined -Wl,-rpath,$PREFIX/lib -Wl,-rpath-link,$PREFIX/lib -L$PREFIX/lib --sysroot=$BUILD_PREFIX/bin/..//x86_64-conda-linux-gnu/sysroot -fstack-protector-strong  FileHandle.o NYTProf.o  -o blib/arch/auto/Devel/NYTProf/NYTProf.so  \
      \

chmod 755 blib/arch/auto/Devel/NYTProf/NYTProf.so
cp blib/arch/auto/Devel/NYTProf/NYTProf.so blib/lib/Devel/auto/Devel/NYTProf/NYTProf.so
cp bin/flamegraph.pl blib/script/flamegraph.pl
"$PREFIX/bin/perl" -MExtUtils::MY -e 'MY->fixin(shift)' -- blib/script/flamegraph.pl
cp bin/nytprofcalls blib/script/nytprofcalls
"$PREFIX/bin/perl" -MExtUtils::MY -e 'MY->fixin(shift)' -- blib/script/nytprofcalls
cp bin/nytprofcg blib/script/nytprofcg
"$PREFIX/bin/perl" -MExtUtils::MY -e 'MY->fixin(shift)' -- blib/script/nytprofcg
cp bin/nytprofcsv blib/script/nytprofcsv
"$PREFIX/bin/perl" -MExtUtils::MY -e 'MY->fixin(shift)' -- blib/script/nytprofcsv
cp bin/nytprofhtml blib/script/nytprofhtml
"$PREFIX/bin/perl" -MExtUtils::MY -e 'MY->fixin(shift)' -- blib/script/nytprofhtml
cp bin/nytprofmerge blib/script/nytprofmerge
"$PREFIX/bin/perl" -MExtUtils::MY -e 'MY->fixin(shift)' -- blib/script/nytprofmerge
cp bin/nytprofpf blib/script/nytprofpf
"$PREFIX/bin/perl" -MExtUtils::MY -e 'MY->fixin(shift)' -- blib/script/nytprofpf
Manifying 6 pod documents
Manifying 9 pod documents
"$PREFIX/bin/perl" -MExtUtils::Command::MM -e 'cp_nonempty' -- NYTProf.bs blib/arch/auto/Devel/NYTProf/NYTProf.bs 644
cp blib/arch/auto/Devel/NYTProf/NYTProf.so blib/lib/Devel/auto/Devel/NYTProf/NYTProf.so
PERL_DL_NONLAZY=1 "$PREFIX/bin/perl" "-MExtUtils::Command::MM" "-MTest::Harness" "-e" "undef *Test::Harness::Switches; test_harness(0, 'blib/lib', 'blib/arch')" t/*.t
# Testing Devel::NYTProf 6.11 started at Wed Oct 26 12:42:07 2022
# Compression: default level is 0, zlib version 0
# --- Perl 5.032001 Config on x86_64-linux-thread-multi:
#       d_gettimeod: define
#       d_sysconf: define
t/00-load.t .............. ok
t/10-run.t ............... ok
t/11-reader.t ............ skipped: ./t/nytprof_11-reader.out.txt doesn't work unless NYTP_ZLIB_VERSION is set
t/12-data.t .............. skipped: ./t/nytprof_12-data.out.txt doesn't work unless NYTP_ZLIB_VERSION is set
t/13-fileinfo.t .......... skipped: ./t/nytprof_13-data.out.txt doesn't work unless NYTP_ZLIB_VERSION is set
t/14-subinfo.t ........... skipped: ./t/nytprof_14-subinfo.out.txt doesn't work unless NYTP_ZLIB_VERSION is set
t/22-readstream.t ........ ok
t/30-util.t .............. ok
t/31-env.t ............... ok
t/40-savesrc.t ........... ok
t/42-global.t ............ ok
t/44-model.t ............. ok
t/50-errno.t ............. ok
t/60-forkdepth.t ......... ok
t/70-subname.t ........... skipped: Sub::Name 0.11 or later required
t/80-version.t ........... ok
t/90-pod.t ............... skipped: NYTPROF_AUTHOR_TESTING only
t/test01.t ............... ok
t/test02.t ............... ok
t/test03.t ............... ok
t/test05.t ............... ok
t/test06.t ............... ok
t/test07.t ............... ok
t/test08.t ............... ok
t/test09.t ............... ok
t/test10.t ............... ok
t/test11.t ............... ok
t/test12.t ............... ok
t/test13.t ............... ok
t/test14.t ............... ok
t/test16.t ............... ok
t/test17-goto.t .......... ok
t/test18-goto2.t ......... ok
t/test20-streval.t ....... ok
t/test21-streval3.t ...... ok
t/test22-strevala.t ...... ok
t/test23-strevall.t ...... ok
t/test24-strevalc.t ...... ok
t/test25-strevalb.t ...... ok
t/test30-fork-0.t ........ ok
t/test40pmc.t ............ ok
t/test50-disable.t ....... ok
t/test51-enable.t ........ ok
t/test60-subname.t ....... ok
t/test61-submerge.t ...... ok

#   Failed test 'test62-subcaller1-a.rdt match generated profile data for blocks=1 calls=1 compress=0 leave=1 savesrc=1 slowops=2 start=init use_db_sub=1'
#   at t/lib/NYTProfTest.pm line 468.
#     Structures begin differing at:
#          $got->[55] = 'fid_line_time  1       4       [ 0 1 ]'
#     $expected->[55] = 'fid_fileinfo   3       [ Exporter.pm   3 2 0 0 ]'
--- test62-subcaller1-a.rdt     2021-09-11 15:50:48.000000000 +0000
+++ test62-subcaller1-a.rdt_new 2022-10-26 12:43:16.942701689 +0000
@@ -53,7 +53,6 @@
 fid_fileinfo   1       call    24      main::sub4      [ 2 0 0 0 0 0 0 main::RUNTIME ]
 fid_fileinfo   2       [ Devel/NYTProf/Test.pm   2 2 0 0 ]
 fid_fileinfo   2       sub     Devel::NYTProf::Test::example_sub       13-13
-fid_fileinfo   3       [ Exporter.pm   3 2 0 0 ]
 fid_line_time  1       4       [ 0 1 ]
 fid_line_time  1       5       [ 0 2 ]
 fid_line_time  1       9       [ 0 1 ]

#   Failed test 'test62-subcaller1-a.rdt match generated profile data for blocks=1 calls=2 compress=1 leave=1 savesrc=1 slowops=2 start=init use_db_sub=1'
#   at t/lib/NYTProfTest.pm line 468.
#     Structures begin differing at:
#          $got->[55] = 'fid_line_time  1       4       [ 0 1 ]'
#     $expected->[55] = 'fid_fileinfo   3       [ Exporter.pm   3 2 0 0 ]'
--- test62-subcaller1-a.rdt     2021-09-11 15:50:48.000000000 +0000
+++ test62-subcaller1-a.rdt_new 2022-10-26 12:43:17.043699751 +0000
@@ -53,7 +53,6 @@
 fid_fileinfo   1       call    24      main::sub4      [ 2 0 0 0 0 0 0 main::RUNTIME ]
 fid_fileinfo   2       [ Devel/NYTProf/Test.pm   2 2 0 0 ]
 fid_fileinfo   2       sub     Devel::NYTProf::Test::example_sub       13-13
-fid_fileinfo   3       [ Exporter.pm   3 2 0 0 ]
 fid_line_time  1       4       [ 0 1 ]
 fid_line_time  1       5       [ 0 2 ]
 fid_line_time  1       9       [ 0 1 ]

#   Failed test 'test62-subcaller1-a.rdt match generated profile data for blocks=1 calls=2 compress=1 leave=1 savesrc=1 slowops=2 start=init use_db_sub=0'
#   at t/lib/NYTProfTest.pm line 468.
#     Structures begin differing at:
#          $got->[55] = 'fid_line_time  1       4       [ 0 1 ]'
#     $expected->[55] = 'fid_fileinfo   3       [ Exporter.pm   3 2 0 0 ]'
--- test62-subcaller1-a.rdt     2021-09-11 15:50:48.000000000 +0000
+++ test62-subcaller1-a.rdt_new 2022-10-26 12:43:17.098698695 +0000
@@ -53,7 +53,6 @@
 fid_fileinfo   1       call    24      main::sub4      [ 2 0 0 0 0 0 0 main::RUNTIME ]
 fid_fileinfo   2       [ Devel/NYTProf/Test.pm   2 2 0 0 ]
 fid_fileinfo   2       sub     Devel::NYTProf::Test::example_sub       13-13
-fid_fileinfo   3       [ Exporter.pm   3 2 0 0 ]
 fid_line_time  1       4       [ 0 1 ]
 fid_line_time  1       5       [ 0 2 ]
 fid_line_time  1       9       [ 0 1 ]

#   Failed test 'test62-subcaller1-a.rdt match generated profile data for blocks=1 calls=0 compress=0 leave=1 savesrc=0 slowops=2 start=init use_db_sub=0'
#   at t/lib/NYTProfTest.pm line 468.
#     Structures begin differing at:
#          $got->[55] = 'fid_line_time  1       4       [ 0 1 ]'
#     $expected->[55] = 'fid_fileinfo   3       [ Exporter.pm   3 2 0 0 ]'
--- test62-subcaller1-a.rdt     2021-09-11 15:50:48.000000000 +0000
+++ test62-subcaller1-a.rdt_new 2022-10-26 12:43:17.153697640 +0000
@@ -53,7 +53,6 @@
 fid_fileinfo   1       call    24      main::sub4      [ 2 0 0 0 0 0 0 main::RUNTIME ]
 fid_fileinfo   2       [ Devel/NYTProf/Test.pm   2 2 0 0 ]
 fid_fileinfo   2       sub     Devel::NYTProf::Test::example_sub       13-13
-fid_fileinfo   3       [ Exporter.pm   3 2 0 0 ]
 fid_line_time  1       4       [ 0 1 ]
 fid_line_time  1       5       [ 0 2 ]
 fid_line_time  1       9       [ 0 1 ]

#   Failed test 'test62-subcaller1-a.rdt match generated profile data for blocks=1 calls=1 compress=1 leave=1 savesrc=0 slowops=2 start=init use_db_sub=1'
#   at t/lib/NYTProfTest.pm line 468.
#     Structures begin differing at:
#          $got->[55] = 'fid_line_time  1       4       [ 0 1 ]'
#     $expected->[55] = 'fid_fileinfo   3       [ Exporter.pm   3 2 0 0 ]'
--- test62-subcaller1-a.rdt     2021-09-11 15:50:48.000000000 +0000
+++ test62-subcaller1-a.rdt_new 2022-10-26 12:43:17.172697275 +0000
@@ -53,7 +53,6 @@
 fid_fileinfo   1       call    24      main::sub4      [ 2 0 0 0 0 0 0 main::RUNTIME ]
 fid_fileinfo   2       [ Devel/NYTProf/Test.pm   2 2 0 0 ]
 fid_fileinfo   2       sub     Devel::NYTProf::Test::example_sub       13-13
-fid_fileinfo   3       [ Exporter.pm   3 2 0 0 ]
 fid_line_time  1       4       [ 0 1 ]
 fid_line_time  1       5       [ 0 2 ]
 fid_line_time  1       9       [ 0 1 ]

#   Failed test 'test62-subcaller1-a.rdt match generated profile data for blocks=1 calls=0 compress=0 leave=0 savesrc=0 slowops=2 start=init use_db_sub=1'
#   at t/lib/NYTProfTest.pm line 468.
#     Structures begin differing at:
#          $got->[55] = 'fid_line_time  1       4       [ 0 1 ]'
#     $expected->[55] = 'fid_fileinfo   3       [ Exporter.pm   3 2 0 0 ]'
--- test62-subcaller1-a.rdt     2021-09-11 15:50:48.000000000 +0000
+++ test62-subcaller1-a.rdt_new 2022-10-26 12:43:17.232696124 +0000
@@ -53,7 +53,6 @@
 fid_fileinfo   1       call    24      main::sub4      [ 2 0 0 0 0 0 0 main::RUNTIME ]
 fid_fileinfo   2       [ Devel/NYTProf/Test.pm   2 2 0 0 ]
 fid_fileinfo   2       sub     Devel::NYTProf::Test::example_sub       13-13
-fid_fileinfo   3       [ Exporter.pm   3 2 0 0 ]
 fid_line_time  1       4       [ 0 1 ]
 fid_line_time  1       5       [ 0 2 ]
 fid_line_time  1       9       [ 0 1 ]

#   Failed test 'test62-subcaller1-a.rdt match generated profile data for blocks=1 calls=1 compress=1 leave=0 savesrc=0 slowops=2 start=init use_db_sub=0'
#   at t/lib/NYTProfTest.pm line 468.
#     Structures begin differing at:
#          $got->[55] = 'fid_line_time  1       4       [ 0 1 ]'
#     $expected->[55] = 'fid_fileinfo   3       [ Exporter.pm   3 2 0 0 ]'
--- test62-subcaller1-a.rdt     2021-09-11 15:50:48.000000000 +0000
+++ test62-subcaller1-a.rdt_new 2022-10-26 12:43:17.334694166 +0000
@@ -53,7 +53,6 @@
 fid_fileinfo   1       call    24      main::sub4      [ 2 0 0 0 0 0 0 main::RUNTIME ]
 fid_fileinfo   2       [ Devel/NYTProf/Test.pm   2 2 0 0 ]
 fid_fileinfo   2       sub     Devel::NYTProf::Test::example_sub       13-13
-fid_fileinfo   3       [ Exporter.pm   3 2 0 0 ]
 fid_line_time  1       4       [ 0 1 ]
 fid_line_time  1       5       [ 0 2 ]
 fid_line_time  1       9       [ 0 1 ]

#   Failed test 'test62-subcaller1-a.rdt match generated profile data for blocks=1 calls=1 compress=0 leave=1 savesrc=1 slowops=2 start=init use_db_sub=0'
#   at t/lib/NYTProfTest.pm line 468.
#     Structures begin differing at:
#          $got->[55] = 'fid_line_time  1       4       [ 0 1 ]'
#     $expected->[55] = 'fid_fileinfo   3       [ Exporter.pm   3 2 0 0 ]'
--- test62-subcaller1-a.rdt     2021-09-11 15:50:48.000000000 +0000
+++ test62-subcaller1-a.rdt_new 2022-10-26 12:43:17.402692861 +0000
@@ -53,7 +53,6 @@
 fid_fileinfo   1       call    24      main::sub4      [ 2 0 0 0 0 0 0 main::RUNTIME ]
 fid_fileinfo   2       [ Devel/NYTProf/Test.pm   2 2 0 0 ]
 fid_fileinfo   2       sub     Devel::NYTProf::Test::example_sub       13-13
-fid_fileinfo   3       [ Exporter.pm   3 2 0 0 ]
 fid_line_time  1       4       [ 0 1 ]
 fid_line_time  1       5       [ 0 2 ]
 fid_line_time  1       9       [ 0 1 ]

#   Failed test 'test62-subcaller1-a.rdt match generated profile data for blocks=1 calls=0 compress=0 leave=1 savesrc=0 slowops=2 start=init use_db_sub=1'
#   at t/lib/NYTProfTest.pm line 468.
#     Structures begin differing at:
#          $got->[55] = 'fid_line_time  1       4       [ 0 1 ]'
#     $expected->[55] = 'fid_fileinfo   3       [ Exporter.pm   3 2 0 0 ]'
--- test62-subcaller1-a.rdt     2021-09-11 15:50:48.000000000 +0000
+++ test62-subcaller1-a.rdt_new 2022-10-26 12:43:17.485691268 +0000
@@ -53,7 +53,6 @@
 fid_fileinfo   1       call    24      main::sub4      [ 2 0 0 0 0 0 0 main::RUNTIME ]
 fid_fileinfo   2       [ Devel/NYTProf/Test.pm   2 2 0 0 ]
 fid_fileinfo   2       sub     Devel::NYTProf::Test::example_sub       13-13
-fid_fileinfo   3       [ Exporter.pm   3 2 0 0 ]
 fid_line_time  1       4       [ 0 1 ]
 fid_line_time  1       5       [ 0 2 ]
 fid_line_time  1       9       [ 0 1 ]

#   Failed test 'test62-subcaller1-a.rdt match generated profile data for blocks=1 calls=1 compress=0 leave=0 savesrc=1 slowops=2 start=init use_db_sub=1'
#   at t/lib/NYTProfTest.pm line 468.
#     Structures begin differing at:
#          $got->[55] = 'fid_line_time  1       4       [ 0 1 ]'
#     $expected->[55] = 'fid_fileinfo   3       [ Exporter.pm   3 2 0 0 ]'
--- test62-subcaller1-a.rdt     2021-09-11 15:50:48.000000000 +0000
+++ test62-subcaller1-a.rdt_new 2022-10-26 12:43:17.504690903 +0000
@@ -53,7 +53,6 @@
 fid_fileinfo   1       call    24      main::sub4      [ 2 0 0 0 0 0 0 main::RUNTIME ]
 fid_fileinfo   2       [ Devel/NYTProf/Test.pm   2 2 0 0 ]
 fid_fileinfo   2       sub     Devel::NYTProf::Test::example_sub       13-13
-fid_fileinfo   3       [ Exporter.pm   3 2 0 0 ]
 fid_line_time  1       4       [ 0 1 ]
 fid_line_time  1       5       [ 0 2 ]
 fid_line_time  1       9       [ 0 1 ]

#   Failed test 'test62-subcaller1-a.rdt match generated profile data for blocks=1 calls=1 compress=0 leave=0 savesrc=1 slowops=2 start=init use_db_sub=0'
#   at t/lib/NYTProfTest.pm line 468.
#     Structures begin differing at:
#          $got->[55] = 'fid_line_time  1       4       [ 0 1 ]'
#     $expected->[55] = 'fid_fileinfo   3       [ Exporter.pm   3 2 0 0 ]'
--- test62-subcaller1-a.rdt     2021-09-11 15:50:48.000000000 +0000
+++ test62-subcaller1-a.rdt_new 2022-10-26 12:43:17.613688812 +0000
@@ -53,7 +53,6 @@
 fid_fileinfo   1       call    24      main::sub4      [ 2 0 0 0 0 0 0 main::RUNTIME ]
 fid_fileinfo   2       [ Devel/NYTProf/Test.pm   2 2 0 0 ]
 fid_fileinfo   2       sub     Devel::NYTProf::Test::example_sub       13-13
-fid_fileinfo   3       [ Exporter.pm   3 2 0 0 ]
 fid_line_time  1       4       [ 0 1 ]
 fid_line_time  1       5       [ 0 2 ]
 fid_line_time  1       9       [ 0 1 ]

#   Failed test 'test62-subcaller1-a.rdt match generated profile data for blocks=1 calls=2 compress=1 leave=0 savesrc=1 slowops=2 start=init use_db_sub=1'
#   at t/lib/NYTProfTest.pm line 468.
#     Structures begin differing at:
#          $got->[55] = 'fid_line_time  1       4       [ 0 1 ]'
#     $expected->[55] = 'fid_fileinfo   3       [ Exporter.pm   3 2 0 0 ]'
--- test62-subcaller1-a.rdt     2021-09-11 15:50:48.000000000 +0000
+++ test62-subcaller1-a.rdt_new 2022-10-26 12:43:17.673687660 +0000
@@ -53,7 +53,6 @@
 fid_fileinfo   1       call    24      main::sub4      [ 2 0 0 0 0 0 0 main::RUNTIME ]
 fid_fileinfo   2       [ Devel/NYTProf/Test.pm   2 2 0 0 ]
 fid_fileinfo   2       sub     Devel::NYTProf::Test::example_sub       13-13
-fid_fileinfo   3       [ Exporter.pm   3 2 0 0 ]
 fid_line_time  1       4       [ 0 1 ]
 fid_line_time  1       5       [ 0 2 ]
 fid_line_time  1       9       [ 0 1 ]

#   Failed test 'test62-subcaller1-a.rdt match generated profile data for blocks=1 calls=1 compress=1 leave=1 savesrc=0 slowops=2 start=init use_db_sub=0'
#   at t/lib/NYTProfTest.pm line 468.
#     Structures begin differing at:
#          $got->[55] = 'fid_line_time  1       4       [ 0 1 ]'
#     $expected->[55] = 'fid_fileinfo   3       [ Exporter.pm   3 2 0 0 ]'
--- test62-subcaller1-a.rdt     2021-09-11 15:50:48.000000000 +0000
+++ test62-subcaller1-a.rdt_new 2022-10-26 12:43:17.793685357 +0000
@@ -53,7 +53,6 @@
 fid_fileinfo   1       call    24      main::sub4      [ 2 0 0 0 0 0 0 main::RUNTIME ]
 fid_fileinfo   2       [ Devel/NYTProf/Test.pm   2 2 0 0 ]
 fid_fileinfo   2       sub     Devel::NYTProf::Test::example_sub       13-13
-fid_fileinfo   3       [ Exporter.pm   3 2 0 0 ]
 fid_line_time  1       4       [ 0 1 ]
 fid_line_time  1       5       [ 0 2 ]
 fid_line_time  1       9       [ 0 1 ]

#   Failed test 'test62-subcaller1-a.rdt match generated profile data for blocks=1 calls=2 compress=1 leave=0 savesrc=1 slowops=2 start=init use_db_sub=0'
#   at t/lib/NYTProfTest.pm line 468.
#     Structures begin differing at:
#          $got->[55] = 'fid_line_time  1       4       [ 0 1 ]'
#     $expected->[55] = 'fid_fileinfo   3       [ Exporter.pm   3 2 0 0 ]'
--- test62-subcaller1-a.rdt     2021-09-11 15:50:48.000000000 +0000
+++ test62-subcaller1-a.rdt_new 2022-10-26 12:43:17.858684110 +0000
@@ -53,7 +53,6 @@
 fid_fileinfo   1       call    24      main::sub4      [ 2 0 0 0 0 0 0 main::RUNTIME ]
 fid_fileinfo   2       [ Devel/NYTProf/Test.pm   2 2 0 0 ]
 fid_fileinfo   2       sub     Devel::NYTProf::Test::example_sub       13-13
-fid_fileinfo   3       [ Exporter.pm   3 2 0 0 ]
 fid_line_time  1       4       [ 0 1 ]
 fid_line_time  1       5       [ 0 2 ]
 fid_line_time  1       9       [ 0 1 ]

#   Failed test 'test62-subcaller1-a.rdt match generated profile data for blocks=1 calls=0 compress=0 leave=0 savesrc=0 slowops=2 start=init use_db_sub=0'
#   at t/lib/NYTProfTest.pm line 468.
#     Structures begin differing at:
#          $got->[55] = 'fid_line_time  1       4       [ 0 1 ]'
#     $expected->[55] = 'fid_fileinfo   3       [ Exporter.pm   3 2 0 0 ]'
--- test62-subcaller1-a.rdt     2021-09-11 15:50:48.000000000 +0000
+++ test62-subcaller1-a.rdt_new 2022-10-26 12:43:17.985681672 +0000
@@ -53,7 +53,6 @@
 fid_fileinfo   1       call    24      main::sub4      [ 2 0 0 0 0 0 0 main::RUNTIME ]
 fid_fileinfo   2       [ Devel/NYTProf/Test.pm   2 2 0 0 ]
 fid_fileinfo   2       sub     Devel::NYTProf::Test::example_sub       13-13
-fid_fileinfo   3       [ Exporter.pm   3 2 0 0 ]
 fid_line_time  1       4       [ 0 1 ]
 fid_line_time  1       5       [ 0 2 ]
 fid_line_time  1       9       [ 0 1 ]

#   Failed test 'test62-subcaller1-a.rdt match generated profile data for blocks=1 calls=1 compress=1 leave=0 savesrc=0 slowops=2 start=init use_db_sub=1'
#   at t/lib/NYTProfTest.pm line 468.
#     Structures begin differing at:
#          $got->[55] = 'fid_line_time  1       4       [ 0 1 ]'
#     $expected->[55] = 'fid_fileinfo   3       [ Exporter.pm   3 2 0 0 ]'
--- test62-subcaller1-a.rdt     2021-09-11 15:50:48.000000000 +0000
+++ test62-subcaller1-a.rdt_new 2022-10-26 12:43:18.010681192 +0000
@@ -53,7 +53,6 @@
 fid_fileinfo   1       call    24      main::sub4      [ 2 0 0 0 0 0 0 main::RUNTIME ]
 fid_fileinfo   2       [ Devel/NYTProf/Test.pm   2 2 0 0 ]
 fid_fileinfo   2       sub     Devel::NYTProf::Test::example_sub       13-13
-fid_fileinfo   3       [ Exporter.pm   3 2 0 0 ]
 fid_line_time  1       4       [ 0 1 ]
 fid_line_time  1       5       [ 0 2 ]
 fid_line_time  1       9       [ 0 1 ]
# SUMMARY: Breakdown of test62-subcaller1-a test failures by option settings:
#           calls: 0 => {FAIL 4}, 1 => {FAIL 8}, 2 => {FAIL 4}
# FAILED with blocks=1:calls=0:compress=0:file=nytprof_test62-subcaller1-a.out:leave=0:savesrc=0:slowops=2:start=init:use_db_sub=0
# FAILED with blocks=1:calls=0:compress=0:file=nytprof_test62-subcaller1-a.out:leave=0:savesrc=0:slowops=2:start=init:use_db_sub=1
# FAILED with blocks=1:calls=0:compress=0:file=nytprof_test62-subcaller1-a.out:leave=1:savesrc=0:slowops=2:start=init:use_db_sub=0
# FAILED with blocks=1:calls=0:compress=0:file=nytprof_test62-subcaller1-a.out:leave=1:savesrc=0:slowops=2:start=init:use_db_sub=1
# FAILED with blocks=1:calls=1:compress=0:file=nytprof_test62-subcaller1-a.out:leave=0:savesrc=1:slowops=2:start=init:use_db_sub=0
# FAILED with blocks=1:calls=1:compress=0:file=nytprof_test62-subcaller1-a.out:leave=0:savesrc=1:slowops=2:start=init:use_db_sub=1
# FAILED with blocks=1:calls=1:compress=0:file=nytprof_test62-subcaller1-a.out:leave=1:savesrc=1:slowops=2:start=init:use_db_sub=0
# FAILED with blocks=1:calls=1:compress=0:file=nytprof_test62-subcaller1-a.out:leave=1:savesrc=1:slowops=2:start=init:use_db_sub=1
# FAILED with blocks=1:calls=1:compress=1:file=nytprof_test62-subcaller1-a.out:leave=0:savesrc=0:slowops=2:start=init:use_db_sub=0
# FAILED with blocks=1:calls=1:compress=1:file=nytprof_test62-subcaller1-a.out:leave=0:savesrc=0:slowops=2:start=init:use_db_sub=1
# FAILED with blocks=1:calls=1:compress=1:file=nytprof_test62-subcaller1-a.out:leave=1:savesrc=0:slowops=2:start=init:use_db_sub=0
# FAILED with blocks=1:calls=1:compress=1:file=nytprof_test62-subcaller1-a.out:leave=1:savesrc=0:slowops=2:start=init:use_db_sub=1
# FAILED with blocks=1:calls=2:compress=1:file=nytprof_test62-subcaller1-a.out:leave=0:savesrc=1:slowops=2:start=init:use_db_sub=0
# FAILED with blocks=1:calls=2:compress=1:file=nytprof_test62-subcaller1-a.out:leave=0:savesrc=1:slowops=2:start=init:use_db_sub=1
# FAILED with blocks=1:calls=2:compress=1:file=nytprof_test62-subcaller1-a.out:leave=1:savesrc=1:slowops=2:start=init:use_db_sub=0
# FAILED with blocks=1:calls=2:compress=1:file=nytprof_test62-subcaller1-a.out:leave=1:savesrc=1:slowops=2:start=init:use_db_sub=1
# Looks like you failed 16 tests of 65.
t/test62-subcaller1-a.t .. 
Dubious, test returned 16 (wstat 4096, 0x1000)
Failed 16/65 subtests 
t/test62-subcaller1-b.t .. skipped: needs perl >= 5.33.3 (see t/test62-subcaller1-a)
t/test62-tie-a.t ......... skipped: needs perl < 5.21.1 (see t/test62-tie-b.t)
t/test62-tie-b.t ......... ok
t/test70-subexcl.t ....... ok
t/test80-recurs.t ........ ok
t/test81-swash.t ......... ok
t/test82-version.t ....... ok
t/test90-strsubref.t ..... ok
# Tests ended at Wed Oct 26 12:43:48 2022
t/zzz.t .................. ok

Test Summary Report
-------------------
t/test62-subcaller1-a.t (Wstat: 4096 Tests: 65 Failed: 16)
  Failed tests:  3, 7, 11, 15, 19, 23, 27, 31, 35, 39, 43
                47, 51, 55, 59, 63
  Non-zero exit status: 16
Files=55, Tests=4736, 101 wallclock secs ( 0.73 usr  0.12 sys + 35.06 cusr  8.03 csys = 43.94 CPU)
Result: FAIL
Failed 1/55 test programs. 16/4736 subtests failed.
make: *** [Makefile:1283: test_dynamic] Error 255

As a side note, on my system Perl, t/12-data.t fails with the following error:

t/12-data.t .............. 1/? 
#   Failed test 'captured exception for file not found'
#   at t/12-data.t line 247.
#                   ''
#     doesn't match '(?^:Devel::NYTProf::new\(\) could not locate file for processing)'
# Looks like you failed 1 test of 79.
t/12-data.t .............. Dubious, test returned 1 (wstat 256, 0x100)
Failed 1/79 subtests 
        (less 3 skipped subtests: 75 okay)

If I can do anything to help find the cause of this issue, please let me know!

jkeenan commented 1 year ago

Hi @jkeenan,

I am currently preparing a CondaForge package recipe for Devel::NYTProf and also get failures with test 62 (t/test62-subcaller1-a.t) in the (dockerized) build environment of CondaForge's CI pipeline. This is version 6.11 of Devel::NYTProf and Perl v5.32.1. When testing with my system Perl (v5.34.1), t/test62-subcaller1-a.t is skipped and the b variant is run instead (it passes). This is the relevant output, containing some more info about package versions and env variables:

I'm at a loss as to how to respond to this. I don't know what CondaForge is. I am aware of Docker but don't use it myself and I generally consider it outside of my remit to debug failures there that are not occuring outside of Docker.

In this and other bug tickets we've discussed the Devel-NYTProf test suite's hypersensitivity to small changes in one's environment. By that we mean that the test suite is chock full of comparisons between a test run and a pre-computed corpus of data. With small changes in one's environment -- and I suspect changes due to Docker would be non-small -- you get output from the test run that is different from the corpus (and is therefore considered a test failure) without necessarily being wrong.

(Indeed, the only reason I am involved in Devel-NYTProf maintenance at all is that changes in the Perl 5 core distribution sometimes trigger failures in Devel-NYTProf's test suite.)

[snip] If I can do anything to help find the cause of this issue, please let me know!

The only thing I can suggest is to run the failing test file manually (i.e., outside your CI pipeline) and examine the results for plausibility. If the results are plausible, then simply skip the file within the pipeline.

xileF1337 commented 1 year ago

Hey @jkeenan,

Some background on CondaForge: it is is a general-purpose package repository for the package manager Conda, which allows users to install arbitrary versions of a software into various virtual environments among other programs, and to activate, deactivate, and manage these environments and so on. This is useful if you need multiple versions of the same software, or if you want to provide a defined working environment to other people or for another computer, e.g. to reproduce scientific results.

The purpose of my report was merely to inform you that this issue with the test exists in certain environments, and to provide some more information that may help to identify the component of the test suite that suffers from this hypersensitivy, as you call it. I do not expect you to provide personal support for my very specific use case, I was just trying to help. If I can do anything to support you in that matter, please let me know.

jkeenan commented 1 year ago

Hey @jkeenan,

Some background on CondaForge: it is is a general-purpose package repository for the package manager Conda, which allows users to install arbitrary versions of a software into various virtual environments among other programs, and to activate, deactivate, and manage these environments and so on. This is useful if you need multiple versions of the same software, or if you want to provide a defined working environment to other people or for another computer, e.g. to reproduce scientific results.

The purpose of my report was merely to inform you that this issue with the test exists in certain environments, and to provide some more information that may help to identify the component of the test suite that suffers from this hypersensitivity, as you call it. I do not expect you to provide personal support for my very specific use case, I was just trying to help. If I can do anything to support you in that matter, please let me know.

Thanks very much for taking the time to provide your original report and this response.