Bug 166677 – Intermittent failures in wasm-to-wasm.js test

• Component: JavaScriptCore
• Status: RESOLVED FIXED

[Saam Barati]

I'm not sure if this is a Wasm bug or a JS bug.
Anyways, it fails maybe 1/10 times for me locally. See shell output:


```
~/WK/c/OpenSource $ ./Tools/Scripts/run-jsc-stress-tests --release JSTests/wasm.yaml 
Using the following jsc path: /Volumes/Data/WK/c/OpenSource/WebKitBuild/Release/jsc
error: /Applications/Xcode.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin/otool: for -S functionality, use llvm-nm with -print-armap


wasm.yaml/wasm/js-api/wasm-to-wasm.js.default-wasm: Exception: Error: Not the same: "1357" and "1357"
wasm.yaml/wasm/js-api/wasm-to-wasm.js.default-wasm: _fail@/Volumes/Data/WK/c/OpenSource/results/.tests/wasm.yaml/wasm/assert.js:27:20
wasm.yaml/wasm/js-api/wasm-to-wasm.js.default-wasm: eq@/Volumes/Data/WK/c/OpenSource/results/.tests/wasm.yaml/wasm/assert.js:83:14
wasm.yaml/wasm/js-api/wasm-to-wasm.js.default-wasm: WasmToWasm@/Volumes/Data/WK/c/OpenSource/results/.tests/wasm.yaml/wasm/js-api/wasm-to-wasm.js:64:18
wasm.yaml/wasm/js-api/wasm-to-wasm.js.default-wasm: module code@/Volumes/Data/WK/c/OpenSource/results/.tests/wasm.yaml/wasm/js-api/wasm-to-wasm.js:66:3
wasm.yaml/wasm/js-api/wasm-to-wasm.js.default-wasm: evaluate@[native code]
wasm.yaml/wasm/js-api/wasm-to-wasm.js.default-wasm: moduleEvaluation@[native code]
wasm.yaml/wasm/js-api/wasm-to-wasm.js.default-wasm: [native code]
wasm.yaml/wasm/js-api/wasm-to-wasm.js.default-wasm: promiseReactionJob@[native code]
wasm.yaml/wasm/js-api/wasm-to-wasm.js.default-wasm: ERROR: Unexpected exit code: 3
155/155 (failed 1)         
~/WK/c/OpenSource $ ./Tools/Scripts/run-jsc-stress-tests --release JSTests/wasm.yaml 
Using the following jsc path: /Volumes/Data/WK/c/OpenSource/WebKitBuild/Release/jsc
error: /Applications/Xcode.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin/otool: for -S functionality, use llvm-nm with -print-armap


155/155         
~/WK/c/OpenSource $ ./Tools/Scripts/run-jsc-stress-tests --release JSTests/wasm.yaml 
Using the following jsc path: /Volumes/Data/WK/c/OpenSource/WebKitBuild/Release/jsc
error: /Applications/Xcode.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin/otool: for -S functionality, use llvm-nm with -print-armap


155/155         
~/WK/c/OpenSource $ ./Tools/Scripts/run-jsc-stress-tests --release JSTests/wasm.yaml 
Using the following jsc path: /Volumes/Data/WK/c/OpenSource/WebKitBuild/Release/jsc
error: /Applications/Xcode.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin/otool: for -S functionality, use llvm-nm with -print-armap


155/155         
~/WK/c/OpenSource $ ./Tools/Scripts/run-jsc-stress-tests --release JSTests/wasm.yaml 
Using the following jsc path: /Volumes/Data/WK/c/OpenSource/WebKitBuild/Release/jsc
error: /Applications/Xcode.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin/otool: for -S functionality, use llvm-nm with -print-armap


155/155         
~/WK/c/OpenSource $ JSC_useConcurrentJIT=0 ./Tools/Scripts/run-jsc-stress-tests --release JSTests/wasm.yaml 
Using the following jsc path: /Volumes/Data/WK/c/OpenSource/WebKitBuild/Release/jsc
error: /Applications/Xcode.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin/otool: for -S functionality, use llvm-nm with -print-armap


155/155         
~/WK/c/OpenSource $ JSC_useConcurrentJIT=0 ./Tools/Scripts/run-jsc-stress-tests --release JSTests/wasm.yaml 
Using the following jsc path: /Volumes/Data/WK/c/OpenSource/WebKitBuild/Release/jsc
error: /Applications/Xcode.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin/otool: for -S functionality, use llvm-nm with -print-armap


155/155         
~/WK/c/OpenSource $ ./Tools/Scripts/run-jsc-stress-tests --release JSTests/wasm.yaml 
Using the following jsc path: /Volumes/Data/WK/c/OpenSource/WebKitBuild/Release/jsc
error: /Applications/Xcode.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin/otool: for -S functionality, use llvm-nm with -print-armap


155/155         
~/WK/c/OpenSource $ ./Tools/Scripts/run-jsc-stress-tests --release JSTests/wasm.yaml 
Using the following jsc path: /Volumes/Data/WK/c/OpenSource/WebKitBuild/Release/jsc
error: /Applications/Xcode.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin/otool: for -S functionality, use llvm-nm with -print-armap


wasm.yaml/wasm/js-api/wasm-to-wasm.js.default-wasm: Exception: Error: Not the same: "594" and "594"
wasm.yaml/wasm/js-api/wasm-to-wasm.js.default-wasm: _fail@/Volumes/Data/WK/c/OpenSource/results/.tests/wasm.yaml/wasm/assert.js:27:20
wasm.yaml/wasm/js-api/wasm-to-wasm.js.default-wasm: eq@/Volumes/Data/WK/c/OpenSource/results/.tests/wasm.yaml/wasm/assert.js:83:14
wasm.yaml/wasm/js-api/wasm-to-wasm.js.default-wasm: WasmToWasm@/Volumes/Data/WK/c/OpenSource/results/.tests/wasm.yaml/wasm/js-api/wasm-to-wasm.js:65:18
wasm.yaml/wasm/js-api/wasm-to-wasm.js.default-wasm: module code@/Volumes/Data/WK/c/OpenSource/results/.tests/wasm.yaml/wasm/js-api/wasm-to-wasm.js:67:3
wasm.yaml/wasm/js-api/wasm-to-wasm.js.default-wasm: evaluate@[native code]
wasm.yaml/wasm/js-api/wasm-to-wasm.js.default-wasm: moduleEvaluation@[native code]
wasm.yaml/wasm/js-api/wasm-to-wasm.js.default-wasm: [native code]
wasm.yaml/wasm/js-api/wasm-to-wasm.js.default-wasm: promiseReactionJob@[native code]
wasm.yaml/wasm/js-api/wasm-to-wasm.js.default-wasm: ERROR: Unexpected exit code: 3
155/155 (failed 1)         
~/WK/c/OpenSource $ ./Tools/Scripts/run-jsc-stress-tests --release JSTests/wasm.yaml 
Using the following jsc path: /Volumes/Data/WK/c/OpenSource/WebKitBuild/Release/jsc
error: /Applications/Xcode.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin/otool: for -S functionality, use llvm-nm with -print-armap


155/155         
~/WK/c/OpenSource $ ./Tools/Scripts/run-jsc-stress-tests --release JSTests/wasm.yaml 
Using the following jsc path: /Volumes/Data/WK/c/OpenSource/WebKitBuild/Release/jsc
error: /Applications/Xcode.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin/otool: for -S functionality, use llvm-nm with -print-armap


155/155         
~/WK/c/OpenSource $ ./Tools/Scripts/run-jsc-stress-tests --release JSTests/wasm.yaml 
Using the following jsc path: /Volumes/Data/WK/c/OpenSource/WebKitBuild/Release/jsc
error: /Applications/Xcode.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin/otool: for -S functionality, use llvm-nm with -print-armap


155/155         
~/WK/c/OpenSource $ ./Tools/Scripts/run-jsc-stress-tests --release JSTests/wasm.yaml 
Using the following jsc path: /Volumes/Data/WK/c/OpenSource/WebKitBuild/Release/jsc
error: /Applications/Xcode.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin/otool: for -S functionality, use llvm-nm with -print-armap


155/155         
~/WK/c/OpenSource $ ./Tools/Scripts/run-jsc-stress-tests --release JSTests/wasm.yaml 
Using the following jsc path: /Volumes/Data/WK/c/OpenSource/WebKitBuild/Release/jsc
error: /Applications/Xcode.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin/otool: for -S functionality, use llvm-nm with -print-armap


155/155         
~/WK/c/OpenSource $ ./Tools/Scripts/run-jsc-stress-tests --release JSTests/wasm.yaml 
Using the following jsc path: /Volumes/Data/WK/c/OpenSource/WebKitBuild/Release/jsc
error: /Applications/Xcode.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin/otool: for -S functionality, use llvm-nm with -print-armap


155/155         
~/WK/c/OpenSource $ ./Tools/Scripts/run-jsc-stress-tests --release JSTests/wasm.yaml 
Using the following jsc path: /Volumes/Data/WK/c/OpenSource/WebKitBuild/Release/jsc
error: /Applications/Xcode.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin/otool: for -S functionality, use llvm-nm with -print-armap


155/155         
~/WK/c/OpenSource $ ./Tools/Scripts/run-jsc-stress-tests --release JSTests/wasm.yaml 
Using the following jsc path: /Volumes/Data/WK/c/OpenSource/WebKitBuild/Release/jsc
error: /Applications/Xcode.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin/otool: for -S functionality, use llvm-nm with -print-armap


155/155         
~/WK/c/OpenSource $ ./Tools/Scripts/run-jsc-stress-tests --release JSTests/wasm.yaml 
Using the following jsc path: /Volumes/Data/WK/c/OpenSource/WebKitBuild/Release/jsc
error: /Applications/Xcode.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin/otool: for -S functionality, use llvm-nm with -print-armap


155/155         
~/WK/c/OpenSource $ ./Tools/Scripts/run-jsc-stress-tests --release JSTests/wasm.yaml 
Using the following jsc path: /Volumes/Data/WK/c/OpenSource/WebKitBuild/Release/jsc
error: /Applications/Xcode.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin/otool: for -S functionality, use llvm-nm with -print-armap


155/155         
~/WK/c/OpenSource $ ./Tools/Scripts/run-jsc-stress-tests --release JSTests/wasm.yaml 
Using the following jsc path: /Volumes/Data/WK/c/OpenSource/WebKitBuild/Release/jsc
error: /Applications/Xcode.app/Contents/Developer/Toolchains/XcodeDefault.xctoolchain/usr/bin/otool: for -S functionality, use llvm-nm with -print-armap


wasm.yaml/wasm/js-api/wasm-to-wasm.js.default-wasm: Exception: Error: Not the same: "594" and "594"
wasm.yaml/wasm/js-api/wasm-to-wasm.js.default-wasm: _fail@/Volumes/Data/WK/c/OpenSource/results/.tests/wasm.yaml/wasm/assert.js:27:20
wasm.yaml/wasm/js-api/wasm-to-wasm.js.default-wasm: eq@/Volumes/Data/WK/c/OpenSource/results/.tests/wasm.yaml/wasm/assert.js:83:14
wasm.yaml/wasm/js-api/wasm-to-wasm.js.default-wasm: WasmToWasm@/Volumes/Data/WK/c/OpenSource/results/.tests/wasm.yaml/wasm/js-api/wasm-to-wasm.js:65:18
wasm.yaml/wasm/js-api/wasm-to-wasm.js.default-wasm: module code@/Volumes/Data/WK/c/OpenSource/results/.tests/wasm.yaml/wasm/js-api/wasm-to-wasm.js:67:3
wasm.yaml/wasm/js-api/wasm-to-wasm.js.default-wasm: evaluate@[native code]
wasm.yaml/wasm/js-api/wasm-to-wasm.js.default-wasm: moduleEvaluation@[native code]
wasm.yaml/wasm/js-api/wasm-to-wasm.js.default-wasm: [native code]
wasm.yaml/wasm/js-api/wasm-to-wasm.js.default-wasm: promiseReactionJob@[native code]
wasm.yaml/wasm/js-api/wasm-to-wasm.js.default-wasm: ERROR: Unexpected exit code: 3
155/155 (failed 1)      
```

[JF Bastien]

That's super weird! I'll take a look. I re-built locally and get the same result you get.

[JF Bastien]

Repro command line:

(cd ./JSTests/wasm/ && lldb ../../current-release/bin/jsc -- -m --useWebAssembly=1 ./js-api/wasm-to-wasm.js --useConcurrentJIT=0 --useJIT=0 --dumpDisassembly=1)

Top of stack is:

* thread #1: tid = 0x17d55c1, 0x0000474c007e26ad, queue = 'com.apple.main-thread', stop reason = EXC_BAD_ACCESS (code=1, address=0x474c007e26ad)
    frame #0: 0x0000474c007e26ad
error: memory read failed for 0x474c007e2600
(lldb) btjs
* thread #1: tid = 0x17d55c1, 0x0000474c007e26ad, queue = 'com.apple.main-thread, stop reason = EXC_BAD_ACCESS (code=1, addre0
    frame #0: 0x0000474c007e26ad 0x474c64001363
    frame #1: 0x0000474c640011be 0x474c64001363
    frame #2: 0x0000474c64001363 0x474c640014e3
    frame #3: 0x0000474c640014e3 0x474c64001536
    frame #4: 0x0000474c64001536 0x1007e16b8
    frame #5: 0x00000001007e16b8 JavaScriptCore`vmEntryToJavaScript + 299
    frame #6: 0x0000000100b6b6c3 JavaScriptCore`JSC::callWebAssemblyFunction(JSC::ExecState*) + 2355

Frame #1 is at:
Generated JIT code for WebAssembly->JavaScript import[0] I32 (I32, I32):
    Code at [0x474c64001140, 0x474c64001220):
      0x474c64001140: push %rbp
      0x474c64001141: mov %rsp, %rbp
      0x474c64001144: mov $0x0, 0x10(%rbp)
      0x474c6400114c: mov $0x1045e40a0, %r11
      0x474c64001156: mov %r11, 0x18(%rbp)
      0x474c6400115a: sub $0x30, %rsp
      0x474c6400115e: mov $0xffff000000000000, %r11
      0x474c64001168: or %r11, %rdi
      0x474c6400116b: mov %rdi, 0x20(%rsp)
      0x474c64001170: mov $0xffff000000000000, %r11
      0x474c6400117a: or %r11, %rsi
      0x474c6400117d: mov %rsi, 0x28(%rsp)
      0x474c64001182: mov 0x1033f5500, %rax
      0x474c6400118c: mov 0x48(%rax), %rax
      0x474c64001190: mov %rax, 0x8(%rsp)
      0x474c64001195: mov $0x3, 0x10(%rsp)
      0x474c6400119d: mov $0xa, 0x18(%rsp)
      0x474c640011a6: mov $0x0, %r11
      0x474c640011b0: cmp %r11, %rax
      0x474c640011b3: jnz 0x474c640011c3
      0x474c640011b9: call 0x474c640011be            # <--- This call
      0x474c640011be: jmp 0x474c640011d2             # Goes here Here!
      0x474c640011c3: mov $0x1030c2800, %rdx
      0x474c640011cd: call 0x474c64001220
      0x474c640011d2: mov $0xffff000000000000, %rdx  # jmp lands here!
      0x474c640011dc: cmp %rdx, %rax
      0x474c640011df: jae 0x474c640011fe
      0x474c640011e5: movq %rax, %xmm0
      0x474c640011ea: cvttsd2si %xmm0, %eax
      0x474c640011ee: test %rax, %rdx
      0x474c640011f1: jnz 0x474c64001200
      0x474c640011f7: mov $0x50, %r11d
      0x474c640011fd: int3 
      0x474c640011fe: mov %eax, %eax
      0x474c64001200: mov %rbp, %rsp
      0x474c64001203: pop %rbp
      0x474c64001204: ret 

Registers for frame #0 are:
General Purpose Registers:
       rax = 0x00000001045572e0
       rbx = 0x0000000000000000
       rcx = 0x00000001030a8c08
       rdx = 0x00007fff5fbfebd0
       rdi = 0xffffbeef00000002
       rsi = 0xffff0000c0febeef
       rbp = 0x00007fff5fbfea40
       rsp = 0x00007fff5fbfea08
        r8 = 0x0000000000000000
        r9 = 0x00000001030a8c08
       r10 = 0x0000474c64001300
       r11 = 0x00000001045572e0
       r12 = 0x0000000000000000
       r13 = 0xdeadfacec0fec0fe
       r14 = 0x00000001045a02d0
       r15 = 0x00000001033f5500
       rip = 0x0000474c007e26ad
    rflags = 0x0000000000000246
        cs = 0x000000000000002b
        fs = 0x0000000000000000
        gs = 0x0000000000000000

But I don't understand how it's getting to this address. Sure it's invalid... but the code from frame #1 doesn't point there! That address isn't mentioned anywhere in the disassembly dump.

Odd.

[JF Bastien]

Created attachment 298055 [details]
WIP

Here's a WIP patch. There are a few things that are wrong, so I have some debugging in there.

Right now it's unhappy about ASSERT(!callee()->isLargeAllocation()); in ExecState::vm.  IIUC it's related to my change in linkDirectFor to avoid using CodeBlock (because wasm doesn't have one). It wasn't failing before though!

Will continue later.

[JF Bastien]

The problem I was initially trying to repro was unrelated to the intermittent failure:
  https://bugs.webkit.org/show_bug.cgi?id=168694
When I don't --useJIT=0, I should be getting the intermittent failure.

Here are repro steps:

  for i in `seq 1 10000`; do (cd ./JSTests/wasm/ && ../../current-release/bin/jsc -m --useWebAssembly=1 ./js-api/wasm-to-wasm.js --useConcurrentJIT=1 --useConcurrentGC=0 --useGC=0) ; printf $?; done; echo "DONE"

The intermittent failure doesn't report *unless* I:

  1. Run some CPU-intensive thing in the background.
  2. Have concurrent JIT *on*.

The GC being on/off doesn't change anything, but having it off means it's definitely not at fault.

[JF Bastien]

Hmm interesting: if I change the 3 constants in that test to 0, then the intermittent failure doesn't occur! This is weird.

[JF Bastien]

Finally back looking at this. It looks like the problem is in baseline.

I can report 100% of the time with the following without needing background work:
  (cd ./JSTests/wasm/ && ../../current-release/bin/jsc -m --useWebAssembly=1 ./js-api/wasm-to-wasm.js --useConcurrentJIT=0 --useDFGJIT=0 --useFTLJIT=0 --useConcurrentGC=0 --useGC=0)

If I move code out of function WasmToWasm I can still report the issue, but I can't remove the loop. It only happens with the loop, and when the loop hits 494.

If I add --useLLInt=0 I can report the issue with:

// ... rest untouched

let value;
const func = (hi, lo) => { value = { hi: hi, lo: lo }; return hi ^ lo; };
const callee = new WebAssembly.Instance(calleeModule(), { imp: { func: func } });
const caller = new WebAssembly.Instance(callerModule(), callee);

(function WasmToWasm() {
    let i = 0;
    caller.exports.entry(i);
    assert.eq(value.hi >>> 0, i);
})();

I'm going to read the bytecode / disassembly and try to understand what the issue is :)

[JF Bastien]

So I think the problem is that baseline tries to do the comparison for 32-bit integers, but what it loads from the object contains crap on top of the int32:

       rax = 0xffffbeef00000000
       rsi = 0xffff000000000000

That beef is from const callerTopBits = 0xC0FEBEEF; and the generated baseline code does this:

    [  84] nstricteq         loc10, loc10, loc7
          0x5ed779aad38b: mov -0x58(%rbp), %rax   <== rematerialize value.hi
          0x5ed779aad38f: mov -0x40(%rbp), %rsi   <== rematerialize i
          0x5ed779aad393: mov %rax, %rdx
          0x5ed779aad396: or %rsi, %rdx
          0x5ed779aad399: test %rdx, %r15
          0x5ed779aad39c: jz 0x5ed779aad663
          0x5ed779aad3a2: cmp %r14, %rax
          0x5ed779aad3a5: jae 0x5ed779aad3b4
          0x5ed779aad3ab: test %rax, %r14
          0x5ed779aad3ae: jnz 0x5ed779aad663
          0x5ed779aad3b4: cmp %r14, %rsi
          0x5ed779aad3b7: jae 0x5ed779aad3c6
          0x5ed779aad3bd: test %rsi, %r14
          0x5ed779aad3c0: jnz 0x5ed779aad663
          0x5ed779aad3c6: cmp %rax, %rsi       <=== this won't work out so well
          0x5ed779aad3c9: setnz %al
          0x5ed779aad3cc: movzx %al, %eax
          0x5ed779aad3cf: or $0x6, %eax
          0x5ed779aad3d2: mov %rax, -0x58(%rbp)

So we're storing unexpected stuff in value.hi. I think teaching the compiler about crappy bits is a bad idea because it's brittle. Instead, I think wasm needs to sanitize when it calls to JS, and it's not doing it.

I'm not 100% sure, but I have to head out for now. Will fix tomorrow.

[JF Bastien]

Created attachment 302483 [details]
patch

Actually this is super easy. I realized I was right and exactly what to fix on my walk. Here's a one-line fix.

[WebKit Commit Bot]

The commit-queue encountered the following flaky tests while processing attachment 302483 [details]:

The commit-queue is continuing to process your patch.

[Build Bot]

Comment on attachment 302483 [details]
patch

Attachment 302483 [details] did not pass mac-debug-ews (mac):
Output: http://webkit-queues.webkit.org/results/3176338

New failing tests:
fast/dom/timer-throttling-hidden-page.html

[Build Bot]

Created attachment 302485 [details]
Archive of layout-test-results from ews116 for mac-elcapitan

The attached test failures were seen while running run-webkit-tests on the mac-debug-ews.
Bot: ews116  Port: mac-elcapitan  Platform: Mac OS X 10.11.6

[JF Bastien]

Comment on attachment 302483 [details]
patch

CQ is Wong.

[WebKit Commit Bot]

Comment on attachment 302483 [details]
patch

Clearing flags on attachment: 302483

Committed r212877: <http://trac.webkit.org/changeset/212877>

[WebKit Commit Bot]

All reviewed patches have been landed.  Closing bug.

[Filip Pizlo]

Comment on attachment 302483 [details]
patch

View in context: https://bugs.webkit.org/attachment.cgi?id=302483&action=review

> Source/JavaScriptCore/ChangeLog:26
> +        fails). We could argue that the baseline compiler is wrong for
> +        performing a 64-bit comparison, but it doesn't really matter

The baseline compiler is right to assume that those bits are zero.  That's a hard-and-fast rule.