Bizarre copy of ARRAY in anonymous array

[eserte]

t/array_id.t fails on some of my smokers like this:

Bizarre copy of ARRAY in anonymous array ([]) at /usr/perl5.33.6p/lib/site_perl/5.33.6/Devel/Cycle.pm line 138.
Attempt to free unreferenced scalar: SV 0x803aa7cf0.
# Tests were run but no plan was declared and done_testing() was not seen.
# Looks like your test exited with 255 just after 25.
t/array_id.t ...................... 
Dubious, test returned 255 (wstat 65280, 0xff00)
All 25 subtests passed 

At the moment, I see the "bizarre copy" messages only with perl 5.33.5 and 5.33.6 installations (but not all are causing also a test failure), so it could be a bleadperl issue.

[dod38fr]

Looks like the failed test is :

memory_cycle_ok( $model, "memory cycles" );

This test is provided by Test::Memory::Cycle which uses Devel::Cycle.

Since I don't use XS in Config::Model, I would be surprised to trigger "Attempt to free unreferenced scalar" errors

Could you test Devel::Cycle in bleadperl ?

[eserte]

Devel::Cycle itself passes with bleadperl:
http://matrix.cpantesters.org/?dist=Devel-Cycle%201.12;perl=5.33.6;reports=1
And I also don't see any "bizarre copy" messages in the test protocols (checked the latest six or seven).

[eserte]

Maybe a BBC? @jkeenan, can you try a bisect? Affected distribution is https://metacpan.org/release/DDUMONT/Config-Model-2.141

[jkeenan]

Maybe a BBC? @jkeenan, can you try a bisect? Affected distribution is https://metacpan.org/release/DDUMONT/Config-Model-2.141

At the moment, when I try to install this distro against blead, using cpanm as the installer, I get an indefinite hang here:

Fetching http://www.cpan.org/authors/id/I/IN/INGY/XXX-0.35.tar.gz ... OK
Configuring XXX-0.35 ... OK
==> Found dependencies: YAML::PP
^C

I think this is a problem with YAML::PP rather than this distro, but until it gets resolved, I'm blocked on diagnosing this problem.

[jkeenan]

Maybe a BBC? @jkeenan, can you try a bisect? Affected distribution is https://metacpan.org/release/DDUMONT/Config-Model-2.141

At the moment, when I try to install this distro against blead, using cpanm as the installer, I get an indefinite hang here:

Fetching http://www.cpan.org/authors/id/I/IN/INGY/XXX-0.35.tar.gz ... OK
Configuring XXX-0.35 ... OK
==> Found dependencies: YAML::PP
^C

I think this is a problem with YAML::PP rather than this distro, but until it gets resolved, I'm blocked on diagnosing this problem.

With assistance from #metacpan contributors, I was able to work around the YAML::PP problem enough to complete the attempted installation of Config-Model. On FreeBSD-12, using clang-10 as the C-compiler, I got the same test failure you did.

Building and testing Config-Model-2.141 ... Checking doc for model Multistrap
Checking doc for model PopCon
Checking doc for model Fstab
Building Config-Model
t/accept.t ........................ ok    
t/annotation.t .................... ok    
t/apply_fix.t ..................... ok    
t/array_id.t ...................... 1/? panic: attempt to copy freed scalar 803df4678 to 804338a50 at /home/jkeenan/testing/blead/lib/perl5/site_perl/5.33.7/Devel/Cycle.pm line 138.
Attempt to free unreferenced scalar: SV 0x803df4678, Perl interpreter: 0x800a9c000.
Attempt to free unreferenced scalar: SV 0x803d5d540, Perl interpreter: 0x800a9c000.
# Tests were run but no plan was declared and done_testing() was not seen.
# Looks like your test exited with 255 just after 25.
t/array_id.t ...................... Dubious, test returned 255 (wstat 65280, 0xff00)
All 25 subtests passed 
t/array_with_data_migration.t ..... ok    

However, until the problem with YAML::PP gets fully fixed, I won't be able to bisect, as each round of bisection against blead requires the full chain of dependencies to complete.

Thank you very much.
Jim Keenan

[jkeenan]

@eserte, I next went the ~/.cpanm/latest-build directory and attempted to build and test using bleadperl. My first attempt failed because a prerequisite not known to cpanm was not installed:

Checking prerequisites...
  recommends:
    *  Fuse is not installed

When I tried to install Fuse, I was next told that I lacked the fusefs-libs library.

Cannot build for platform: freebsd
You need to install the "fusefs-libs" package from ports to support this module
-> N/A
-> FAIL Configure failed for Fuse-0.16. See /home/jkeenan/.cpanm/work/1611426463.7919/build.log for details.

So I installed that library and once again attempted to install against blead.

PERL_DL_NONLAZY=1 "/usr/home/jkeenan/testing/blead/bin/perl" "-Iblib/lib" "-Iblib/arch" test.pl
# mounting examples/loopback.pl to /tmp/fusemnt-jkeenan
# Mounted in 5.1 secs

#   Failed test 'mount succeeded'
#   at test/s/mount.t line 34.
cat: /usr/home/jkeenan/.cpanm/work/1611426692.93765/Fuse-0.16/test/s/mounted.pid: No such file or directory
# Looks like you failed 1 test of 3.
test/s/mount.t ...
[snip]
Can't exec "fusermount": No such file or directory at test/s/umount.t line 6.
umount: /tmp/fusemnt-jkeenan: not a file system root directory

#   Failed test 'unmount'
#   at test/s/umount.t line 10.
# Looks like you failed 1 test of 1.
test/s/umount.t ..

I don't know whether this installation failure for Fuse is the cause of the test failure for Config-Model. Suggestions?

If I get a chance I will try this on Linux.

[jkeenan]

@eserte, I next went the ~/.cpanm/latest-build directory and attempted to build and test using bleadperl. My first attempt failed because a prerequisite not known to cpanm was not installed:

Checking prerequisites...
  recommends:
    *  Fuse is not installed

When I tried to install Fuse, I was next told that I lacked the fusefs-libs library.

Cannot build for platform: freebsd
You need to install the "fusefs-libs" package from ports to support this module
-> N/A
-> FAIL Configure failed for Fuse-0.16. See /home/jkeenan/.cpanm/work/1611426463.7919/build.log for details.

So I installed that library and once again attempted to install against blead.

PERL_DL_NONLAZY=1 "/usr/home/jkeenan/testing/blead/bin/perl" "-Iblib/lib" "-Iblib/arch" test.pl
# mounting examples/loopback.pl to /tmp/fusemnt-jkeenan
# Mounted in 5.1 secs

#   Failed test 'mount succeeded'
#   at test/s/mount.t line 34.
cat: /usr/home/jkeenan/.cpanm/work/1611426692.93765/Fuse-0.16/test/s/mounted.pid: No such file or directory
# Looks like you failed 1 test of 3.
test/s/mount.t ...
[snip]
Can't exec "fusermount": No such file or directory at test/s/umount.t line 6.
umount: /tmp/fusemnt-jkeenan: not a file system root directory

#   Failed test 'unmount'
#   at test/s/umount.t line 10.
# Looks like you failed 1 test of 1.
test/s/umount.t ..

I don't know whether this installation failure for Fuse is the cause of the test failure for Config-Model. Suggestions?

Correction: It appears that at some point in the past few hours I actually did get Config-Model to install against bleadperl. I can't say how that happened because I was multi-tasking. However, now, when I go into the .cpanm/latest-build directory and run the test, sometimes the test passes but throws warning:

ok 26 - memory cycles
1..26
Attempt to free unreferenced scalar: SV 0x8043308a0, Perl interpreter: 0x800a9c000 at t/array_id.t line 556.
Attempt to free unreferenced scalar: SV 0x803df0330, Perl interpreter: 0x800a9c000 at t/array_id.t line 556.
ok
All tests successful.

or

[perlmonger: Config-Model-2.141] $ ./Build test
t/accept.t ........................ ok    
t/annotation.t .................... ok    
t/apply_fix.t ..................... ok    
t/array_id.t ...................... 4/? Attempt to free unreferenced scalar: SV 0x803de7270, Perl interpreter: 0x800a9c000 at t/array_id.t line 556.
Attempt to free unreferenced scalar: SV 0x80433b048, Perl interpreter: 0x800a9c000 at t/array_id.t line 556.
t/array_id.t ...................... ok    

... but sometimes the test FAILS and throws warnings:

$ bleadprove -b t/array_id.t
t/array_id.t .. 4/? Bizarre copy of HASH in anonymous array ([]) at /home/jkeenan/testing/blead/lib/perl5/site_perl/5.33.7/Devel/Cycle.pm line 138.
Attempt to free unreferenced scalar: SV 0x8043311f8, Perl interpreter: 0x800a9c000.
Attempt to free unreferenced scalar: SV 0x803de19c0, Perl interpreter: 0x800a9c000.
# Tests were run but no plan was declared and done_testing() was not seen.
# Looks like your test exited with 255 just after 25.
t/array_id.t .. Dubious, test returned 255 (wstat 65280, 0xff00)
All 25 subtests passed 

Test Summary Report
-------------------
t/array_id.t (Wstat: 65280 Tests: 25 Failed: 0)
  Non-zero exit status: 255
  Parse errors: No plan found in TAP output
Files=1, Tests=25,  1 wallclock secs ( 0.08 usr  0.00 sys +  0.61 cusr  0.04 csys =  0.73 CPU)
Result: FAIL

[jkeenan]

Here are two different results from running the same command in the same directory.

$ bleadperl -Iblib/lib t/array_id.t
...
ok 25 - test load_data with node list
ok 26 - memory cycles
1..26
Attempt to free unreferenced scalar: SV 0x803ca07e0, Perl interpreter: 0x800a9c000 at t/array_id.t line 556.
Attempt to free unreferenced scalar: SV 0x803df7f60, Perl interpreter: 0x800a9c000 at t/array_id.t line 556.

$ bleadperl -Iblib/lib t/array_id.t
ok 1 - compiled
...
ok 25 - test load_data with node list
panic: attempt to copy freed scalar 803b73c18 to 8042ff318 at /home/jkeenan/testing/blead/lib/perl5/site_perl/5.33.7/Devel/Cycle.pm line 138.
Attempt to free unreferenced scalar: SV 0x803df30a8, Perl interpreter: 0x800a9c000.
Attempt to free unreferenced scalar: SV 0x803b73c18, Perl interpreter: 0x800a9c000.
# Tests were run but no plan was declared and done_testing() was not seen.
# Looks like your test exited with 255 just after 25.

So the unit test that is failing is #26, memory cycles

[eserte]

I don't know whether this installation failure for Fuse is the cause of the test failure for Config-Model. Suggestions?

@jkeenan : Fuse is just a "recommends" dependency, and I think it's not installed on my smokers (at least not on all), and probably it's irrelevant for the problem.

[jkeenan]

On Linux I find the following:

1. At head on blead, t/array_id.t fails on both unthreaded and threaded builds.
2. I've begun to test at the tags associated with recent dev releases. Preliminary results suggest that problem emerged between 5.33.2 and 5.33.3.
   Are you in a position to set up a bisection with those --start/--end points?

Thank you very much.
Jim Keenan

[jkeenan]

I made several attempts at bisecting this problem on threaded builds on Linux, but was unsuccessful each time. I used commands like this:

perl Porting/bisect.pl -Duseithreads --start=v5.33.2  --end=v5.33.6 \
    --module=Config::Model

... varying the --end value from v5.33.3 to v.5.33.6. In each case, my bisection terminated relatively quickly apparently showing the run at the --end commit to be successful (whereas we would have expected to get a failure). Example:

  DDUMONT/Config-Model-2.141.tar.gz
  ./Build install  -- OK
HEAD is now at 7b99455 add new release to perlhist
good - zero exit from /tmp/FJfbJH0IJI/bin/perl -I /home/jkeenan/.cpan -MCPAN::MyConfig -MCPAN -e $CPAN::Config->{build_dir}=q{/tmp/cqeIenAwzv}; -e install('Config::Model'); die unless CPAN::Shell->expand(Module => 'Config::Model')->uptodate;
Runner returned 0 for end revision at Porting/bisect.pl line 233.
That took 2481 seconds.

I do not yet know how to proceed.

[dod38fr]

Note that Config::Model uses a lot of weak variables to avoid memory cycles. There variables are weakened by Mouse (with weak_ref attribute parameter) or weaken function from Scalar::Util.

It's possible that the problem seen with bleadperl come from these modules.

HTH

[hvds]

Hi Dominique, I've managed to show in the linked perl5 ticket that there's clearly a perl bug going on here; however it is being triggered by the splice() in Config::Model::ListId->remove(), and I suspect there's a bug somewhere around here in your module too.

In the t/array_id.t subtest "preset clear stuff", the eventual effect of the preset_clear call is that Config::Model::Instance->_stuff_clear() will iterate over a precomputed list of keys (0, 1, 2, 3) calling $obj->remove($key) on each one. This will invoke the splice() mentioned above to actually remove the items, so the indexes of the remaining items are changing even as you try to iterate over them.

The only reason it doesn't go wrong even more badly is that fetch_summary(), called to create the change notification, is ensuring the keys are autovivified just before they are spliced out; without that you'd be seeing "splice() offset past end of array" errors for keys 2 and 3.

Hope this helps,

Hugo

[dod38fr]

Hi Hugo

Many, many, thanks for the detailed analysis. 🙏

There's indeed a big issue which shows up after tweaking a little bit the "preset clear stuff" tests. I've tried to fix this by applying the splice in reverse order (i.e. using reverse @keys), but then another test blows up. I guess there's another bug hidden there 🤦

All the best