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

Process tests sometimes cause timeout on Linux #1

Closed
sgjesse opened this issue Oct 6, 2011 · 2 comments
Closed

Process tests sometimes cause timeout on Linux #1

sgjesse opened this issue Oct 6, 2011 · 2 comments
Assignees

Comments

@sgjesse
Copy link
Contributor

sgjesse commented Oct 6, 2011

Either of the process tests

  ProcessExitTest.dart
  ProcessSegfaultTest.dart
  ProcessStartExceptionTest.dart
  ProcessStderrTest.dart
  ProcessStdoutTest.dart

can hang on Linux. It happens once every ~25 runs.

@DartBot
Copy link

DartBot commented Oct 7, 2011

This comment was originally written by fmalita@google.com


Hanging stack trace:

#­0 0xf77c0430 in __kernel_vsyscall ()
#­1 0xf7476e43 in __lll_lock_wait_private () at ../nptl/sysdeps/unix/sysv/linux/i386/i686/../i486/lowlevellock.S:95
#­2 0xf740c367 in _L_lock_9639 () from /lib32/libc.so.6
#­3 0xf740ab96 in __libc_free (mem=0xa138448) at malloc.c:3736
#­4 0xf75f4a91 in operator delete(void*) () from /usr/lib32/libstdc++.so.6
#­5 0x0805d697 in ExitHandle (processSignal=17, siginfo=0xfff1d9bc, tmp=0xfff1da3c) at ../runtime/bin/process_linux.cc:70
#­6 <signal handler called>
#­7 0xf740896d in _int_malloc (av=<value optimized out>, bytes=<value optimized out>) at malloc.c:4500
#­8 0xf740ac6c in __libc_malloc (bytes=520) at malloc.c:3660
#­9 0xf75f6f87 in operator new(unsigned int) () from /usr/lib32/libstdc++.so.6
#­10 0x08076644 in dart::Handles<2, 64, 4>::SetupNextZoneBlock (this=0xfff1eac8) at ../runtime/vm/handles_impl.h:184
#­11 0x08076339 in dart::Handles<2, 64, 4>::AllocateHandleInZone (this=0xfff1eac8) at ../runtime/vm/handles.h:182
#­12 0x08075e67 in dart::Handles<2, 64, 4>::AllocateZoneHandle () at ../runtime/vm/handles_impl.h:70
#­13 0x08074f17 in dart::VMHandles::AllocateZoneHandle () at ../runtime/vm/handles.cc:45
#­14 0x080beb5e in dart::Type::ZoneHandle (raw_ptr=0xf3202361) at ../runtime/vm/object.h:727
#­15 0x080c257c in dart::ParamList::AddReceiver(int) ()

We're calling unsafe functions (delete/free) in the SIGCHLD handler, deadlocking glibc's allocator.

@sgjesse
Copy link
Contributor Author

sgjesse commented Oct 19, 2011

This was fixed in https://code.google.com/p/dart/source/detail?r=325.


Added Fixed label.

@sgjesse sgjesse self-assigned this Oct 19, 2011
copybara-service bot pushed a commit that referenced this issue Sep 25, 2024
…ecks

The (utf8) scanner currently has this thing where you give it a
0-terminated byte-array (i.e. you read the file, then allocate
something that's 1 bigger, copy the data, then give it to the scanner)
to 'avoid bounds checks'.
Dart still has bounds checks though - they're just implicit.

As for the string scanner ut gets a string, then creates a new string
like `string + '\x00'` - so basically the same thing.

This CL uses the 'vm:unsafe:no-bounds-checks' pragma, removing the
implicit bounds checks, adding explicit bounds checks,
saving ~73.6 mio instructions when compiling the CFE in the process:

```
Comparing snapshot #1 with snapshot #2
cycles:u: -0.9983% +/- 0.6563% (-174026333.30 +/- 114410028.98)
instructions:u: -0.3416% +/- 0.0005% (-73659267.00 +/- 108567.20)
branch-misses:u: -4.8952% +/- 2.2612% (-3172939.50 +/- 1465641.18)
```

With the scanner-benchmark with `--bytes` I get this:

```
msec task-clock:u: -1.2251% +/- 0.6355% (-50.64 +/- 26.27)
cycles:u: -1.2376% +/- 0.6385% (-223642830.80 +/- 115393789.68)
instructions:u: -2.8155% +/- 0.0000% (-1153243856.00 +/- 428.11)
seconds time elapsed: -1.2165% +/- 0.6408% (-0.05 +/- 0.03)
seconds user: -1.1539% +/- 0.6495% (-0.05 +/- 0.03)
```

With the scanner-benchmark with `--string` I get this:

```
msec task-clock:u: -7.6439% +/- 0.6628% (-366.08 +/- 31.74)
page-faults:u: -95.0034% +/- 0.0014% (-228023.50 +/- 3.41)
instructions:u: 2.1041% +/- 0.0000% (897941907.60 +/- 2082.79)
branch-misses:u: 3.2994% +/- 1.4675% (3239735.30 +/- 1440940.88)
seconds time elapsed: -7.6595% +/- 0.6610% (-0.37 +/- 0.03)
seconds user: -0.8801% +/- 0.7676% (-0.04 +/- 0.03)
seconds sys: -92.0140% +/- 2.8075% (-0.33 +/- 0.01)
MarkSweep(   old space) goes from 6 to 0
Notice combined GC time goes from 112 ms to 41 ms (notice only 1 run each).
```

Where I'll note that the 'vm:unsafe:no-bounds-checks' pragma doesn't
(yet?) work for `String.codeUnitAt`.
See https://dart-review.googlesource.com/c/sdk/+/384540
(and https://dart-review.googlesource.com/c/sdk/+/385201) for details.
I assume the relatively  big change here is caused by not allocating
a new string with a 0-byte in the end each time.

Note that the read-allocate-copy dance is still performed for the utf8
scanner in this CL as it requires changing all call-sites instead.
It will be done in a follow-up CL where the "end-of-file" int will
likely also be changed to `-1` to (I assume) allow for having the
0-byte in the middle of a file (see also the 10+ year old bug at
#18090)

Note: The pragma (currently?) only has effect in AOT and this change
will (for the utf8 scanner) make the JIT version slower
(probably by the same ~73.6 mio instructions as - at least in AOT -
the implicit check is 6 instructions and the explicit one is 3
instructions). As the pragma doesn't work in the StringScanner anyway
I expect the change to be somewhat equivalent there. Once the
read-allocate-copy dance is also removed from the utf8 scanner I expect
the combined result to be positive all around.

Update: With https://dart-review.googlesource.com/c/sdk/+/385201 landed
I get these changes:

Compiling the CFE:
```
instructions:u: -0.4520% +/- 0.0002% (-98470955.29 +/- 42253.40)
```

Scanner benchmark with `--bytes`:

```
msec task-clock:u: -2.1758% +/- 0.2316% (-92.07 +/- 9.80)
cycles:u: -2.1941% +/- 0.2283% (-405224983.11 +/- 42160655.88)
instructions:u: -3.1049% +/- 0.0000% (-1272360052.95 +/- 706.54)
branch-misses:u: 2.4718% +/- 0.5142% (2371345.23 +/- 493257.76)
seconds time elapsed: -2.1761% +/- 0.2317% (-0.09 +/- 0.01)
seconds user: -2.2071% +/- 0.2308% (-0.09 +/- 0.01)
```

Scanner benchmark with `--string`:

```
msec task-clock:u: -15.0073% +/- 0.2175% (-745.93 +/- 10.81)
page-faults:u: -95.0035% +/- 0.0003% (-228024.25 +/- 0.81)
cycles:u: -7.7986% +/- 0.2329% (-1558985588.99 +/- 46560962.79)
instructions:u: -3.7054% +/- 0.0000% (-1581977447.66 +/- 481.68)
branch-misses:u: -0.6880% +/- 0.5818% (-689453.22 +/- 583101.50)
seconds time elapsed: -15.0198% +/- 0.2170% (-0.75 +/- 0.01)
seconds user: -8.8149% +/- 0.2648% (-0.41 +/- 0.01)
seconds sys: -94.1247% +/- 1.6444% (-0.34 +/- 0.01)
MarkSweep(   old space) goes from 6 to 0
```

Change-Id: I524a21f488da7df5dc9d2cdf40112b84896ad3e0
Reviewed-on: https://dart-review.googlesource.com/c/sdk/+/383324
Reviewed-by: Brian Wilkerson <brianwilkerson@google.com>
Reviewed-by: Johnni Winther <johnniwinther@google.com>
Commit-Queue: Jens Johansen <jensj@google.com>
copybara-service bot pushed a commit that referenced this issue Oct 22, 2024
See: b/374689139.

https://dart-review.googlesource.com/c/sdk/+/390941 is blocking an SDK roll.

Root cause:


```
Action threw an exception: type 'ConstructorMember' is not a subtype of type 'ConstructorFragment' in type cast
#0      InterfaceTypeImpl.constructors2.<anonymous closure> (package:analyzer/src/dart/element/type.dart:569)
#1      MappedListIterable.elementAt (dart:_internal/iterable.dart:435)
#2      ListIterator.moveNext (dart:_internal/iterable.dart:364)
#3      new _GrowableList._ofEfficientLengthIterable (dart:core-patch/growable_array.dart:189)
#4      new _GrowableList.of (dart:core-patch/growable_array.dart:150)
#5      new List.of (dart:core-patch/array_patch.dart:39)
#6      ListIterable.toList (dart:_internal/iterable.dart:224)
#7      InterfaceTypeImpl.constructors2 (package:analyzer/src/dart/element/type.dart:570)
#8      _Visitor._hasConstConstructorInvocation (package:linter/src/rules/prefer_const_constructors_in_immutables.dart:110)
#9      _Visitor.visitConstructorDeclaration (package:linter/src/rules/prefer_const_constructors_in_immutables.dart:58)
```


To verify the fix locally:

```
  solo_test_X() async {
    await assertNoErrorsInCode(r'''
class A<T> {}
''');

    var A = findElement.class_('A').instantiate(
      typeArguments: [intType],
      nullabilitySuffix: NullabilitySuffix.none,
    );
    A.constructors2;
  }
```


Bug: b/374689139
Change-Id: I70034d938d840dc0c3939db27e7116164e4617e9
Reviewed-on: https://dart-review.googlesource.com/c/sdk/+/391483
Reviewed-by: Konstantin Shcheglov <scheglov@google.com>
Commit-Queue: Phil Quitslund <pquitslund@google.com>
@ARDUTECH0 ARDUTECH0 mentioned this issue Dec 28, 2024
copybara-service bot pushed a commit that referenced this issue Jan 31, 2025
## Added --cache to benchmarker.dart

This doubles the amount of runs by running an additional round of `perf
stat` runs outputting low level cache information: L1-icache-load-misses
(instruction load misses), LLC-loads (last level cache loads, i.e.
probably how many loads goes to L3 cache) and LLC-load-misses (last
level cache load misses, i.e. how many loads goes to ram). I don't know
if these are generally available, only that they are available on my
machine.

## Added --silent to benchmarker.dart

Some benchmarks output information to stdout which is great when running
it by hand, but when running it via the benchmarker script it just
pollutes the output: The benchmarker script et al measures what is
supposed to be measured. This CL adds the `--silent` option to the
benchmarker script which then won't print the stdout output from the
benchmarkee.

## Output filename in benchmarker.dart

This CL adds the filenames of the benchmarked snapshots in an attempt to
avoid confusion. Example output before:

```
Comparing snapshot #1 with snapshot #2
```

```
Example output now:
Comparing snapshot #1 (optimization_attempt_41.aot) with snapshot #2 (optimization_attempt_42.aot)
```

## Utility to summarize --verbose-gc output

Takes input from --verbose-gc from stdin and summarizes the time taken
on GC and reports it back. Example:

```
$ out/ReleaseX64/dart --verbose-gc hello.dart 2> /dev/stdout 1> /dev/null | out/ReleaseX64/dart pkg/front_end/tool/verbose_gc_helper.dart
6.1
```

Change-Id: I206f21cd8b42f844e60358aed711e676e453c77c
Reviewed-on: https://dart-review.googlesource.com/c/sdk/+/406845
Reviewed-by: Johnni Winther <johnniwinther@google.com>
Commit-Queue: Jens Johansen <jensj@google.com>
copybara-service bot pushed a commit that referenced this issue Feb 11, 2025
This is a possible fix for the following benign TSAN error:

WARNING: ThreadSanitizer: data race (pid=40436)
  Read of size 8 at 0x7b7c000bfa48 by thread T6 (mutexes: write M0):
    #0 dart::Page::object_end() const out/ReleaseTSANX64/../../runtime/vm/heap/page.h (dart+0x25ade83)
    #1 dart::Page::used() const out/ReleaseTSANX64/../../runtime/vm/heap/page.h:107:34 (dart+0x25ade83)
    #2 dart::SemiSpace::used_in_words() const out/ReleaseTSANX64/../../runtime/vm/heap/scavenger.h:46:18 (dart+0x25ade83)
    #3 dart::Scavenger::UsedInWords() const out/ReleaseTSANX64/../../runtime/vm/heap/scavenger.h:157:17 (dart+0x25ade83)
    #4 dart::GetProcessMemoryUsageHelper(dart::JSONStream*)::$_0::operator()(dart::IsolateGroup*) const out/ReleaseTSANX64/../../runtime/vm/service.cc:4729:50 (dart+0x25ade83)

  Previous write of size 8 at 0x7b7c000bfa48 by thread T9:
    #0 dart::Thread::set_top(unsigned long) out/ReleaseTSANX64/../../runtime/vm/thread.h:698:34 (dart+0x2622071)
    #1 dart::Scavenger::TryAllocateFromTLAB(dart::Thread*, long) out/ReleaseTSANX64/../../runtime/vm/heap/scavenger.h:256:13 (dart+0x2622071)
    #2 dart::Scavenger::TryAllocate(dart::Thread*, long) out/ReleaseTSANX64/../../runtime/vm/heap/scavenger.h:139:12 (dart+0x2622071)
    #3 dart::Heap::AllocateNew(dart::Thread*, long) out/ReleaseTSANX64/../../runtime/vm/heap/heap.cc:84:27 (dart+0x2622071)
    #4 dart::Heap::Allocate(dart::Thread*, long, dart::Heap::Space) out/ReleaseTSANX64/../../runtime/vm/heap/heap.h:87:16 (dart+0x2416cab)

TEST=ci

Change-Id: Id9077cff2c1143adf999b2b26c941701d63cd844
Reviewed-on: https://dart-review.googlesource.com/c/sdk/+/409180
Reviewed-by: Ryan Macnak <rmacnak@google.com>
Commit-Queue: Alexander Markov <alexmarkov@google.com>
copybara-service bot pushed a commit that referenced this issue Feb 12, 2025
…terrupted

Thread interrupts can be disabled after thread interrupter decided to
interrupt a thread but before thread actually receives and handles
a signal.

This may cause a data race accessing a Sample between profiler which
initializes and adds a Sample and the main thread using
Profiler::sample_block_buffer() in the profiler unit tests.

This is a possible fix for the following benign TSAN error:

WARNING: ThreadSanitizer: data race (pid=5824)
  Write of size 4 at 0x7f53e8e53a98 by thread T6:
    #0 dart::Sample::set_thread_task(dart::Thread::TaskKind) out/ReleaseTSANX64/../../runtime/vm/profiler.h:325:12 (run_vm_tests+0x292cab2)
    #1 dart::SetupSample(dart::Thread*, bool, unsigned long) out/ReleaseTSANX64/../../runtime/vm/profiler.cc:1226:11 (run_vm_tests+0x292cab2)
    #2 dart::Profiler::SampleThread(dart::Thread*, dart::InterruptedThreadState const&) out/ReleaseTSANX64/../../runtime/vm/profiler.cc:1381:7 (run_vm_tests+0x292cab2)
    #3 dart::ThreadInterrupterLinux::ThreadInterruptSignalHandler(int, siginfo_t*, void*) out/ReleaseTSANX64/../../runtime/vm/thread_interrupter_linux.cc:44:5 (run_vm_tests+0x2a064b0)
    #4 __tsan::CallUserSignalHandler(__tsan::ThreadState*, bool, bool, int, __sanitizer::__sanitizer_siginfo*, void*) ../staging/llvm_build/tools/clang/stage2-bins/runtimes/runtimes-x86_64-unknown-linux-gnu-bins/compiler-rt/lib/tsan/rtl/tsan_interceptors_posix.cpp:2122:5 (run_vm_tests+0x1fc057f)
    #5 dart::Mutex::Unlock() out/ReleaseTSANX64/../../runtime/vm/os_thread_linux.cc:367:16 (run_vm_tests+0x2924b89)

  Previous read of size 4 at 0x7f53e8e53a98 by main thread:
    #0 dart::Sample::head_sample() const out/ReleaseTSANX64/../../runtime/vm/profiler.h:350:59 (run_vm_tests+0x22c70e7)
    #1 dart::SampleBuffer::VisitSamples(dart::SampleVisitor*) out/ReleaseTSANX64/../../runtime/vm/profiler.h:589:20 (run_vm_tests+0x22c70e7)
    #2 dart::SampleBlockBuffer::VisitSamples(dart::SampleVisitor*) out/ReleaseTSANX64/../../runtime/vm/profiler.h:752:18 (run_vm_tests+0x22c70e7)
    #3 dart::Dart_TestHelperProfiler_GetSourceReport(dart::Thread*) out/ReleaseTSANX64/../../runtime/vm/profiler_test.cc:2241:26 (run_vm_tests+0x22c70e7)
    #4 dart::Dart_TestProfiler_GetSourceReport() out/ReleaseTSANX64/../../runtime/vm/profiler_test.cc:2206:1 (run_vm_tests+0x22c70e7)
    #5 dart::TestCase::Run() out/ReleaseTSANX64/../../runtime/bin/run_vm_tests.cc:53:3 (run_vm_tests+0x203fe6c)

--- Re-run this test:
python3 tools/test.py -n vm-tsan-linux-release-x64 vm/cc/Profiler_GetSourceReport

Also, this change is a possible fix for #44089.

TEST=ci

Change-Id: I8ad87c340580325cbd6e22b5f068e1e33b0a7d46
Reviewed-on: https://dart-review.googlesource.com/c/sdk/+/409460
Reviewed-by: Ryan Macnak <rmacnak@google.com>
Commit-Queue: Alexander Markov <alexmarkov@google.com>
copybara-service bot pushed a commit that referenced this issue Feb 21, 2025
This test has a few independent calls to asyncExpectThrows which uses
asyncStart/asyncEnd. However, multiple top-level asyncStart/asyncEnd
are not allowed, which causes the following flaky error:

```
Unhandled exception:
Exception: Fatal: asyncStart() was called even though we are done with testing.. This is most likely a bug in your test.
#0      asyncStart (package:expect/async_helper.dart:53)
#1      asyncExpectThrows (package:expect/async_helper.dart:140)
#2      testMalformedAuthenticateHeaderWithAuthHandler.<anonymous closure> (file:///b/s/w/ir/cache/builder/sdk/tests/standalone/io/http_auth_digest_test.dart:345)
#3      Future._propagateToListeners.handleValueCallback (dart:async/future_impl.dart:951)
#4      Future._propagateToListeners (dart:async/future_impl.dart:980)
#5      Future._completeWithValue (dart:async/future_impl.dart:723)
#6      Future._asyncCompleteWithValue.<anonymous closure> (dart:async/future_impl.dart:807)
#7      _microtaskLoop (dart:async/schedule_microtask.dart:40)
#8      _startMicrotaskLoop (dart:async/schedule_microtask.dart:49)
#9      _runPendingImmediateCallback (dart:isolate-patch/isolate_patch.dart:128)
#10     _RawReceivePort._handleMessage (dart:isolate-patch/isolate_patch.dart:195)

--- Re-run this test:
python3 tools/test.py -n vm-aot-ubsan-linux-release-x64 standalone/io/http_auth_digest_test
```

This change attempts to fix this by adding a top-level asyncStart/asyncEnd
and also asyncStart/asyncEnd to the server start/shutdown to
enclose each test case into asyncStart/asyncEnd and avoid printing
"unittest-suite-success" marker before all test cases are finished.

TEST=standalone/io/http_auth_digest_test

Change-Id: I950e7c6c09f5c2144da874ab3be3cd3a130d3790
Reviewed-on: https://dart-review.googlesource.com/c/sdk/+/411086
Commit-Queue: Alexander Markov <alexmarkov@google.com>
Reviewed-by: Alexander Aprelev <aam@google.com>
This issue was closed.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants