Code aborts while working with supplies #4804

p6rt · 2015-12-01T08:53:21Z

Migrated from rt.perl.org#126774 (status was 'resolved')

Searchable as RT126774$

p6rt · 2015-12-01T08:53:22Z

From @zostay

This report is going to be a bit ugly since this code isn't published
anywhere to point to and I'm not sure how I could possibly reduce it, but
it's only four small files, so hopefully this is useful.

I am getting an abort while executing this program. It does not always
happen at the same point, sometimes as early as after the 4th iteration and
sometimes as late as after the 5th in http-1.0.t. When I run it against
valgrind, it gives the following trace which is the most information I've
gotten on what's going on. I have placed the log below.

Attached are the files required to see this problem in action. The test
file t/http-1.0.t, the test data files t/data/http-1.0-close.txt and
t/data/http-1.0-dumb.txt, and the package I am working on
lib/HTTP1/StreamParser.pm6.

I am working on OS X, but I get the same result running it on in my Linux
VM. I am running with rakudo on moar built with rakudobrew this evening
(updated shortly before 12/1/15 12:48 AM PST).

It is very likely that I've done something incorrect in my code, which is
causing this as I'm still getting a feel for how supply and react blocks
work, but I'm confident also that regardless of whether my code is right or
wrong, it shouldn't be aborting while apparently performing garbage
collection on my code either.

Cheers.

% perl6-valgrind-m -Ilib t/http-1.0.t

This is Rakudo Perl 6 running in valgrind, a tool for debugging and
profiling programs.
Running a program in valgrind usually takes *a lot* more time than running
it directly,
so please be patient.
This Rakudo version is 2015.11.311.gf.94.c.31.e built on MoarVM version
2015.11.21.g.469.ba.64,
running on macosx (10.10.5) / darwin (14.5.0)

==7204== Memcheck, a memory error detector
==7204== Copyright (C) 2002-2015, and GNU GPL'd, by Julian Seward et al.
==7204== Using Valgrind-3.11.0 and LibVEX; rerun with -h for copyright info
==7204== Command: /Users/sterling/.rakudobrew/moar-nom/install/bin/moar
--execname=/Users/sterling/.rakudobrew/bin/../moar-nom/install/bin/perl6-valgrind-m
--libpath=/Users/sterling/.rakudobrew/moar-nom/install/share/nqp/lib
--libpath=/Us
ers/sterling/.rakudobrew/moar-nom/install/share/perl6/lib
--libpath=/Users/sterling/.rakudobrew/moar-nom/install/share/perl6/runtime
/Users/sterling/.rakudobrew/moar-nom/install/share/perl6/runtime/perl6.moarvm
-Ilib t/http-1.0.t
==7204==
--7204-- run: /usr/bin/dsymutil
"/Users/sterling/.rakudobrew/moar-nom/install/bin/moar"
warning: no debug symbols in executable (-arch x86_64)
--7204-- run: /usr/bin/dsymutil
"/Users/sterling/.rakudobrew/moar-nom/install/lib/libmoar.dylib"
warning: no debug symbols in executable (-arch x86_64)
--7204-- run: /usr/bin/dsymutil
"/Users/sterling/.rakudobrew/moar-nom/install/share/perl6/runtime/dynext/libperl6_ops_moar.dylib"
--7204-- UNKNOWN mach_msg unhandled MACH_SEND_TRAILER option
--7204-- UNKNOWN mach_msg unhandled MACH_SEND_TRAILER option (repeated 2
times)
--7204-- UNKNOWN mach_msg unhandled MACH_SEND_TRAILER option (repeated 4
times)
--7204:0:syswrap- WARNING: Ignoring sigreturn( ..., UC_RESET_ALT_STACK );
--7204:0:syswrap- WARNING: Ignoring sigreturn( ..., UC_RESET_ALT_STACK );
--7204:0:syswrap- WARNING: Ignoring sigreturn( ..., UC_RESET_ALT_STACK );
--7204:0:syswrap- WARNING: Ignoring sigreturn( ..., UC_RESET_ALT_STACK );
--7204:0:syswrap- WARNING: Ignoring sigreturn( ..., UC_RESET_ALT_STACK );
--7204:0:syswrap- WARNING: Ignoring sigreturn( ..., UC_RESET_ALT_STACK );
--7204:0:syswrap- WARNING: Ignoring sigreturn( ..., UC_RESET_ALT_STACK );
--7204:0:syswrap- WARNING: Ignoring sigreturn( ..., UC_RESET_ALT_STACK );
--7204:0:syswrap- WARNING: Ignoring sigreturn( ..., UC_RESET_ALT_STACK );
--7204:0:syswrap- WARNING: Ignoring sigreturn( ..., UC_RESET_ALT_STACK );
--7204:0:syswrap- WARNING: Ignoring sigreturn( ..., UC_RESET_ALT_STACK );
--7204:0:syswrap- WARNING: Ignoring sigreturn( ..., UC_RESET_ALT_STACK );
--7204:0:syswrap- WARNING: Ignoring sigreturn( ..., UC_RESET_ALT_STACK );
--7204:0:syswrap- WARNING: Ignoring sigreturn( ..., UC_RESET_ALT_STACK );
--7204:0:syswrap- WARNING: Ignoring sigreturn( ..., UC_RESET_ALT_STACK );
--7204:0:syswrap- WARNING: Ignoring sigreturn( ..., UC_RESET_ALT_STACK );
1..40
==7204== Thread 3:
==7204== Invalid read of size 4
==7204== at 0x1000E3D9E: uv__stream_osx_select (in
/Users/sterling/.rakudobrew/moar-nom/install/lib/libmoar.dylib)
==7204== by 0x1000E59A8: uv__thread_start (in
/Users/sterling/.rakudobrew/moar-nom/install/lib/libmoar.dylib)
==7204== by 0x1006EA059: _pthread_body (in
/usr/lib/system/libsystem_pthread.dylib)
==7204== by 0x1006E9FD6: _pthread_start (in
/usr/lib/system/libsystem_pthread.dylib)
==7204== by 0x1006E73EC: thread_start (in
/usr/lib/system/libsystem_pthread.dylib)
==7204== Address 0x100b93aeb is 203 bytes inside a block of size 206
alloc'd
==7204== at 0x100009EBB: malloc (in
/usr/local/Cellar/valgrind/3.11.0/lib/valgrind/vgpreload_memcheck-amd64-darwin.so)
==7204== by 0x1000E3962: uv__stream_try_select (in
/Users/sterling/.rakudobrew/moar-nom/install/lib/libmoar.dylib)
==7204== by 0x1000E701B: uv_tty_init (in
/Users/sterling/.rakudobrew/moar-nom/install/lib/libmoar.dylib)
==7204== by 0x10004D0C2: MVM_file_get_stdstream (in
/Users/sterling/.rakudobrew/moar-nom/install/lib/libmoar.dylib)
==7204== by 0x1000C43CF: MVM_vm_create_instance (in
/Users/sterling/.rakudobrew/moar-nom/install/lib/libmoar.dylib)
==7204== by 0x100001658: main (in
/Users/sterling/.rakudobrew/moar-nom/install/bin/moar)
==7204==
--7204:0:syswrap- WARNING: Ignoring sigreturn( ..., UC_RESET_ALT_STACK );
--7204:0:syswrap- WARNING: Ignoring sigreturn( ..., UC_RESET_ALT_STACK );
--7204:0:syswrap- WARNING: Ignoring sigreturn( ..., UC_RESET_ALT_STACK );
ok 1 - environment looks good
ok 2 - input found in environment
ok 3 - message body looks good
ok 4 - no more requests expected
ok 5 - environment looks good
ok 6 - input found in environment
ok 7 - message body looks good
ok 8 - no more requests expected
ok 9 - environment looks good
ok 10 - input found in environment
ok 11 - message body looks good
ok 12 - no more requests expected
ok 13 - environment looks good
ok 14 - input found in environment
ok 15 - message body looks good
ok 16 - no more requests expected
==7204==
==7204== Process terminating with default action of signal 6 (SIGABRT)
==7204== at 0x1005D42B6: __pthread_sigmask (in
/usr/lib/system/libsystem_kernel.dylib)
==7204== by 0x1004E8A40: __abort (in
/usr/lib/system/libsystem_c.dylib)==7204== by 0x1004E89C1: abort (in
/usr/lib/system/libsystem_c.dylib)
==7204== by 0x1000E5A23: uv_mutex_destroy (in
/Users/sterling/.rakudobrew/moar-nom/install/lib/libmoar.dylib)
==7204== by 0x1000718A1: gc_free (in
/Users/sterling/.rakudobrew/moar-nom/install/lib/libmoar.dylib)
==7204== by 0x1000475DF: MVM_gc_collect_free_nursery_uncopied (in
/Users/sterling/.rakudobrew/moar-nom/install/lib/libmoar.dylib)
==7204== by 0x100044906: run_gc (in
/Users/sterling/.rakudobrew/moar-nom/install/lib/libmoar.dylib)
==7204== by 0x1000442BD: MVM_gc_enter_from_allocator (in
/Users/sterling/.rakudobrew/moar-nom/install/lib/libmoar.dylib)
==7204== by 0x100044A77: MVM_gc_allocate_zeroed (in
/Users/sterling/.rakudobrew/moar-nom/install/lib/libmoar.dylib)
==7204== by 0x100044D03: MVM_gc_allocate_object (in
/Users/sterling/.rakudobrew/moar-nom/install/lib/libmoar.dylib)
==7204== by 0x10002BE2B: MVM_frame_takeclosure (in
/Users/sterling/.rakudobrew/moar-nom/install/lib/libmoar.dylib)
==7204== by 0x100019727: MVM_interp_run (in
/Users/sterling/.rakudobrew/moar-nom/install/lib/libmoar.dylib)
==7204==
==7204== HEAP SUMMARY:
==7204== in use at exit: 82,500,601 bytes in 272,148 blocks
==7204== total heap usage: 417,278 allocs, 145,130 frees, 157,048,335
bytes allocated
==7204==
==7204== LEAK SUMMARY:
==7204== definitely lost: 148,938 bytes in 1,868 blocks
==7204== indirectly lost: 28,049 bytes in 1,538 blocks
==7204== possibly lost: 82,223,890 bytes in 268,008 blocks
==7204== still reachable: 64,432 bytes in 303 blocks
==7204== suppressed: 35,292 bytes in 431 blocks
==7204== Rerun with --leak-check=full to see details of leaked memory
==7204==
==7204== For counts of detected and suppressed errors, rerun with: -v
==7204== ERROR SUMMARY: 13 errors from 1 contexts (suppressed: 0 from 0)
/Users/sterling/.rakudobrew/bin/../moar-nom/install/bin/perl6-valgrind-m:
line 11: 7204 Killed: 9 valgrind
/Users/sterling/.rakudobrew/moar-nom/install/bin/moar --execname="$0"
--libpath="/Users/sterling/.rakudobrew/moar-no
m/install/share/nqp/lib"
--libpath="/Users/sterling/.rakudobrew/moar-nom/install/share/perl6/lib"
--libpath="/Users/sterling/.rakudobrew/moar-nom/install/share/perl6/runtime"
/Users/sterling/.rakudobrew/moar-nom/install/share/perl6/runtim
e/perl6.moarvm "$@"
--
Sterling Hanenkamp
http://sterling.hanenkamp.com/stfl/
785-370-4454

p6rt · 2015-12-01T08:53:22Z

From @zostay

POST /index.html HTTP/1.0
Content-Type: application/x-www-form-urlencoded; charset=utf8
Content-Length: 11
Authorization: Basic QWxhZGRpbjpvcGVuIHNlc2FtZQ==
Referer: http://example.com/awesome.html
Connection: close
User-Agent: Mozilla/Inf

a=1&b=2&c=3

p6rt · 2015-12-01T08:53:22Z

From @zostay

#!smackup
use v6;

use Test;
use HTTP1::StreamParser;

my @chunk-sizes = 1, 3, 11, 101, 1009;
my @tests =
{
source => 'http-1.0-close.txt',
expected => $[{
REQUEST_METHOD => 'POST',
REQUEST_URI => '/index.html',
SERVER_PROTOCOL => 'HTTP/1.0',
CONTENT_TYPE => 'application/x-www-form-urlencoded; charset=utf8',
CONTENT_LENGTH => '11',
HTTP_AUTHORIZATION => 'Basic QWxhZGRpbjpvcGVuIHNlc2FtZQ==',
HTTP_REFERER => 'http://example.com/awesome.html',
HTTP_CONNECTION => 'close',
HTTP_USER_AGENT => 'Mozilla/Inf',
'p6w.input' => 'a=1&b=2&c=3',
}],
},
{
source => 'http-1.0-dumb.txt',
expected => $[{
REQUEST_METHOD => 'POST',
REQUEST_URI => '/index.html',
SERVER_PROTOCOL => 'HTTP/1.0',
CONTENT_TYPE => 'application/x-www-form-urlencoded; charset=utf8',
CONTENT_LENGTH => '11',
HTTP_AUTHORIZATION => 'Basic QWxhZGRpbjpvcGVuIHNlc2FtZQ==',
HTTP_REFERER => 'http://example.com/awesome.html',
HTTP_CONNECTION => 'close',
HTTP_USER_AGENT => 'Mozilla/Inf',
'p6w.input' => 'a=1&b=2&c=3',
}],
},
;

plan @tests * @chunk-sizes * 4;

for @tests -> $test {

# Run the tests at various chunk sizes
for @chunk-sizes -> $chunk-size {
my $test-file = "t/data/$test<source>".IO;
my $envs = parse-http1-request(
$test-file.open(:r).Supply(:size($chunk-size), :bin)
);

my @expected = $test<expected>;

react {
whenever $envs -> %env {
my %exp = @expected.shift;

flunk 'unexpected environment received: ', %env.perl
unless %exp.defined;

my $input = %env<p6w.input> :delete;
my $content = %exp<p6w.input> :delete;

is-deeply %env, %exp, 'environment looks good';

ok $input.defined, 'input found in environment';

my $acc = buf8.new;
react {
whenever $input -> $chunk {
$acc ~= $chunk;
}
$input.wait;

CATCH {
default {
warn $_;
flunk $_;
}
}
}

is $acc.decode('utf8'), $content, 'message body looks good';

LAST {
is @expected.elems, 0, 'no more requests expected';
}

QUIT {
warn $_;
flunk $_;
}
}
}

CATCH {
default {
warn $_;
flunk $_;
}
}
}
}

p6rt · 2015-12-01T08:53:22Z

From @zostay

POST /index.html HTTP/1.0
Content-Type: application/x-www-form-urlencoded; charset=utf8
Content-Length: 11
Authorization: Basic QWxhZGRpbjpvcGVuIHNlc2FtZQ==
Referer: http://example.com/awesome.html
User-Agent: Mozilla/Inf

a=1&b=2&c=3

p6rt · 2015-12-01T08:53:22Z

From @zostay

StreamParser.pm6

p6rt · 2015-12-03T23:26:45Z

From @zostay

I've been doing some digging on this because it's basically holding up my ability to test the code I'm working on. It appears that a thread is being garbage collected, but it's aborting because pthread_mutex_destroy is returning an error code when libuv attempts to free up the thread resources.

I suspect that the version of libuv used by MVM contains an old bug that is hurting my particular program. I'm continuing to dig, but my C is pretty rusty.

p6rt · 2016-11-02T16:13:52Z

From @jnthn

On Thu Dec 03 15:26:45 2015, hanenkamp wrote:

I've been doing some digging on this because it's basically holding up
my ability to test the code I'm working on. It appears that a thread
is being garbage collected, but it's aborting because
pthread_mutex_destroy is returning an error code when libuv attempts
to free up the thread resources.

I suspect that the version of libuv used by MVM contains an old bug
that is hurting my particular program. I'm continuing to dig, but my C
is pretty rusty.

It was a mutex being garbage collected (fine) but that was still locked (not fine). MoarVM now detects when that happens and panics with a more informative error. But - more helpfully - I believe I tracked down and fixed the case where this happens. The test in S17-supply/return-in-tap.t covers it (though I suspect there were quite a few more code paths that could lead to the same problem). Since the bug was filed, many other fixes have also been applied to supplies.

Since this looks very much like something I fixed yesterday, but there's no reproduction details for me to verify it, I'll resolve this; feel free to re-open or re-file (with more details if possible) if this is still an issue.

Thanks,

/jnthn

p6rt · 2016-11-02T16:13:52Z

The RT System itself - Status changed from 'new' to 'open'

p6rt · 2016-11-02T16:13:53Z

@jnthn - Status changed from 'open' to 'resolved'

p6rt closed this as completed Nov 2, 2016

p6rt added conc SEGV Segmentation fault, bus error, etc. labels Jan 5, 2020

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Code aborts while working with supplies #4804

Code aborts while working with supplies #4804

p6rt commented Dec 1, 2015

p6rt commented Dec 1, 2015

p6rt commented Dec 1, 2015

p6rt commented Dec 1, 2015

p6rt commented Dec 1, 2015

p6rt commented Dec 1, 2015

p6rt commented Dec 3, 2015

p6rt commented Nov 2, 2016

p6rt commented Nov 2, 2016

p6rt commented Nov 2, 2016

Code aborts while working with supplies #4804

Code aborts while working with supplies #4804

Comments

p6rt commented Dec 1, 2015

p6rt commented Dec 1, 2015

From @zostay

% perl6-valgrind-m -Ilib t/http-1.0.t

p6rt commented Dec 1, 2015

From @zostay

p6rt commented Dec 1, 2015

From @zostay

p6rt commented Dec 1, 2015

From @zostay

p6rt commented Dec 1, 2015

From @zostay

p6rt commented Dec 3, 2015

From @zostay

p6rt commented Nov 2, 2016

From @jnthn

p6rt commented Nov 2, 2016

p6rt commented Nov 2, 2016