AtomicFlagTest.SetOnDifferentSequenceDeathTest failing in 64-bit release clang/win builds |
|||
Issue descriptionStarted here: https://build.chromium.org/p/chromium.fyi/builders/CrWinClang64%28dll%29%20tester/builds/6432 https://luci-logdog.appspot.com/v/?s=chromium%2Fbb%2Fchromium.fyi%2FCrWinClang64_dll__tester%2F6432%2F%2B%2Frecipes%2Fsteps%2Fbase_unittests%2F0%2Flogs%2FAtomicFlagTest.SetOnDifferentSequenceDeathTest%2F0 [ RUN ] AtomicFlagTest.SetOnDifferentSequenceDeathTest ../../base/synchronization/atomic_flag_unittest.cc(23): error: Death test: flag->Set() Result: failed to die. Error msg: [ DEATH ] [3300:1532:0901/122316.568:10871631:WARNING:test_suite.cc(235)] Test launcher output path C:\Users\CHROME~2\AppData\Local\Temp\4328_24438\test_results.xml exists. Not adding test launcher result printer. [ DEATH ] [ FAILED ] AtomicFlagTest.SetOnDifferentSequenceDeathTest (45 ms) I don't see any CLs that touch this code :-/
,
Sep 12 2017
It passes when I try it locally. We had two passing builds on 8 September, so it feels a little flaky. As Nico said, I don't see any interesting Chromium commits in the first failing build, 6432.
,
Sep 12 2017
Aha! I can repro locally.. if I run it 10 times or so :-)
,
Sep 12 2017
The test code looks like this:
Thread t("AtomicFlagTest.SetOnDifferentThreadDeathTest");
ASSERT_TRUE(t.Start());
EXPECT_TRUE(t.WaitUntilThreadStarted());
AtomicFlag flag;
flag.Set();
t.task_runner()->PostTask(FROM_HERE, BindOnce(&ExpectSetFlagDeath, &flag));
The paranoid me wonders if it's possible for the last two lines to execute out-of-order, so that ExpectSetFlagDeath runs on the background thread *before* the "flag.Set()" statements...
No, that doesn't make sense. :-/
,
Sep 12 2017
> the "flag.Set()" statements... *statement
,
Sep 12 2017
Anyway, what got me thinking along those lines is that flag.Set() writes to the flag with std::memory_order_release, so there is no acquire-release relationship between the writes to the flag on the two threads. But one would imagine the whole PostTask thing would make stuff synchronized..
,
Sep 12 2017
Moving the first "flag.set()" to before the thread creation makes the test pass reliably for me:
diff --git a/base/synchronization/atomic_flag_unittest.cc b/base/synchronization/atomic_flag_unittest.cc
index a7c4d9c1e7da..3022afac65e8 100644
--- a/base/synchronization/atomic_flag_unittest.cc
+++ b/base/synchronization/atomic_flag_unittest.cc
@@ -118,12 +118,14 @@ TEST(AtomicFlagTest, SetOnDifferentSequenceDeathTest) {
// on this one. AtomicFlag should die on a DCHECK if Set() is called again
// from another sequence.
::testing::FLAGS_gtest_death_test_style = "threadsafe";
+
+ AtomicFlag flag;
+ flag.Set();
+
Thread t("AtomicFlagTest.SetOnDifferentThreadDeathTest");
ASSERT_TRUE(t.Start());
EXPECT_TRUE(t.WaitUntilThreadStarted());
- AtomicFlag flag;
- flag.Set();
t.task_runner()->PostTask(FROM_HERE, BindOnce(&ExpectSetFlagDeath, &flag));
}
,
Sep 12 2017
The sequence checks inside AtomicFlag::Set take a mutex lock though, so reordering seems surprising at least..
,
Sep 12 2017
?TestBody@AtomicFlagTest_SetOnDifferentSequenceDeathTest_Test@base@@EEAAXXZ (private: virtual void __cdecl base::AtomicFlagTest_SetOnDifferentSequenceDeathTest_Test::TestBody(void)):
0000000000000000: 41 57 push r15
0000000000000002: 41 56 push r14
0000000000000004: 41 54 push r12
0000000000000006: 56 push rsi
0000000000000007: 57 push rdi
0000000000000008: 53 push rbx
0000000000000009: 48 81 EC 48 01 00 sub rsp,148h
00
0000000000000010: 48 8B 05 00 00 00 mov rax,qword ptr [__security_cookie]
00
0000000000000017: 48 89 84 24 40 01 mov qword ptr [rsp+140h],rax
00 00
000000000000001F: 48 8D 0D 00 00 00 lea rcx,[?FLAGS_gtest_death_test_style@testing@@3V?$basic_string@DU?$char_traits@D@std@@V?$allocator@D@2@@std@@A]
00
0000000000000026: 48 8D 15 00 00 00 lea rdx,[??_C@_0L@IJHBEGHO@threadsafe?$AA@]
00
000000000000002D: E8 00 00 00 00 call ?assign@?$basic_string@DU?$char_traits@D@std@@V?$allocator@D@2@@std@@QEAAAEAV12@PEBD@Z
0000000000000032: B8 0F 00 00 00 mov eax,0Fh
0000000000000037: 66 48 0F 6E C0 movd xmm0,rax
000000000000003C: 66 0F 73 F8 08 pslldq xmm0,8
0000000000000041: 48 8D B4 24 80 00 lea rsi,[rsp+80h]
00 00
0000000000000049: F3 0F 7F 46 10 movdqu xmmword ptr [rsi+10h],xmm0
000000000000004E: C6 06 00 mov byte ptr [rsi],0
0000000000000051: 48 8D 15 00 00 00 lea rdx,[??_C@_0CN@CMLIOOMP@AtomicFlagTest?4SetOnDifferentThr@]
00
0000000000000058: 48 89 F1 mov rcx,rsi
000000000000005B: E8 00 00 00 00 call ?assign@?$basic_string@DU?$char_traits@D@std@@V?$allocator@D@2@@std@@QEAAAEAV12@PEBD@Z
0000000000000060: 48 8D BC 24 A0 00 lea rdi,[rsp+0A0h]
00 00
0000000000000068: 48 89 F9 mov rcx,rdi
000000000000006B: 48 89 F2 mov rdx,rsi
000000000000006E: FF 15 00 00 00 00 call qword ptr [__imp_??0Thread@base@@QEAA@AEBV?$basic_string@DU?$char_traits@D@std@@V?$allocator@D@2@@std@@@Z]
0000000000000074: 48 89 F1 mov rcx,rsi
0000000000000077: E8 00 00 00 00 call ??1?$basic_string@DU?$char_traits@D@std@@V?$allocator@D@2@@std@@QEAA@XZ
000000000000007C: 48 89 F9 mov rcx,rdi
000000000000007F: FF 15 00 00 00 00 call qword ptr [__imp_?Start@Thread@base@@QEAA_NXZ]
0000000000000085: 88 44 24 30 mov byte ptr [rsp+30h],al
0000000000000089: 48 C7 44 24 38 00 mov qword ptr [rsp+38h],0
00 00 00
0000000000000092: 84 C0 test al,al
0000000000000094: 0F 84 A3 01 00 00 je 000000000000023D
000000000000009A: 48 8D 74 24 38 lea rsi,[rsp+38h]
000000000000009F: 31 D2 xor edx,edx
00000000000000A1: 48 89 F1 mov rcx,rsi
00000000000000A4: E8 00 00 00 00 call ?reset@?$scoped_ptr@V?$basic_string@DU?$char_traits@D@std@@V?$allocator@D@2@@std@@@internal@testing@@QEAAXPEAV?$basic_string@DU?$char_traits@D@std@@V?$allocator@D@2@@std@@@Z
00000000000000A9: 48 8D 8C 24 A0 00 lea rcx,[rsp+0A0h]
00 00
00000000000000B1: FF 15 00 00 00 00 call qword ptr [__imp_?WaitUntilThreadStarted@Thread@base@@QEBA_NXZ]
00000000000000B7: 88 46 F8 mov byte ptr [rsi-8],al
00000000000000BA: 48 C7 06 00 00 00 mov qword ptr [rsi],0
00
00000000000000C1: 84 C0 test al,al
00000000000000C3: 0F 85 97 00 00 00 jne 0000000000000160
00000000000000C9: 48 8D 74 24 78 lea rsi,[rsp+78h]
00000000000000CE: 48 89 F1 mov rcx,rsi
00000000000000D1: E8 00 00 00 00 call ??0Message@testing@@QEAA@XZ
00000000000000D6: 48 8D 05 00 00 00 lea rax,[??_C@_04LOAJBDKD@true?$AA@]
00
00000000000000DD: 48 89 44 24 20 mov qword ptr [rsp+20h],rax
00000000000000E2: 4C 8D 05 00 00 00 lea r8,[??_C@_0BL@FHKJECKE@t?4WaitUntilThreadStarted?$CI?$CJ?$AA@]
00
00000000000000E9: 4C 8D 0D 00 00 00 lea r9,[??_C@_05LAPONLG@false?$AA@]
00
00000000000000F0: 48 8D BC 24 80 00 lea rdi,[rsp+80h]
00 00
00000000000000F8: 48 8D 54 24 30 lea rdx,[rsp+30h]
00000000000000FD: 48 89 F9 mov rcx,rdi
0000000000000100: E8 00 00 00 00 call ?GetBoolAssertionFailureMessage@internal@testing@@YA?AV?$basic_string@DU?$char_traits@D@std@@V?$allocator@D@2@@std@@AEBVAssertionResult@2@PEBD11@Z
0000000000000105: 48 83 7F 18 0F cmp qword ptr [rdi+18h],0Fh
000000000000010A: 48 89 F8 mov rax,rdi
000000000000010D: 76 08 jbe 0000000000000117
000000000000010F: 48 8B 84 24 80 00 mov rax,qword ptr [rsp+80h]
00 00
0000000000000117: 48 89 44 24 20 mov qword ptr [rsp+20h],rax
000000000000011C: 4C 8D 05 00 00 00 lea r8,[??_C@_0DD@CJJFAE@?4?4?1?4?4?1base?1synchronization?1atomi@]
00
0000000000000123: 48 8D 5C 24 68 lea rbx,[rsp+68h]
0000000000000128: BA 01 00 00 00 mov edx,1
000000000000012D: 41 B9 7B 00 00 00 mov r9d,7Bh
0000000000000133: 48 89 D9 mov rcx,rbx
0000000000000136: E8 00 00 00 00 call ??0AssertHelper@internal@testing@@QEAA@W4Type@TestPartResult@2@PEBDH1@Z
000000000000013B: 48 89 D9 mov rcx,rbx
000000000000013E: 48 89 F2 mov rdx,rsi
0000000000000141: E8 00 00 00 00 call ??4AssertHelper@internal@testing@@QEBAXAEBVMessage@2@@Z
0000000000000146: 48 89 D9 mov rcx,rbx
0000000000000149: E8 00 00 00 00 call ??1AssertHelper@internal@testing@@QEAA@XZ
000000000000014E: 48 89 F9 mov rcx,rdi
0000000000000151: E8 00 00 00 00 call ??1?$basic_string@DU?$char_traits@D@std@@V?$allocator@D@2@@std@@QEAA@XZ
0000000000000156: 31 D2 xor edx,edx
0000000000000158: 48 89 F1 mov rcx,rsi
000000000000015B: E8 00 00 00 00 call ?reset@?$scoped_ptr@V?$basic_stringstream@DU?$char_traits@D@std@@V?$allocator@D@2@@std@@@internal@testing@@QEAAXPEAV?$basic_stringstream@DU?$char_traits@D@std@@V?$allocator@D@2@@std@@@Z
0000000000000160: 48 8D 4C 24 38 lea rcx,[rsp+38h]
0000000000000165: 31 D2 xor edx,edx
0000000000000167: E8 00 00 00 00 call ?reset@?$scoped_ptr@V?$basic_string@DU?$char_traits@D@std@@V?$allocator@D@2@@std@@@internal@testing@@QEAAXPEAV?$basic_string@DU?$char_traits@D@std@@V?$allocator@D@2@@std@@@Z
000000000000016C: 4C 8D BC 24 80 00 lea r15,[rsp+80h]
00 00
0000000000000174: 4C 89 F9 mov rcx,r15
0000000000000177: FF 15 00 00 00 00 call qword ptr [__imp_??0AtomicFlag@base@@QEAA@XZ]
000000000000017D: 4C 89 F9 mov rcx,r15
0000000000000180: FF 15 00 00 00 00 call qword ptr [__imp_?Set@AtomicFlag@base@@QEAAXXZ] <----------- flag.Set()
0000000000000186: 48 8D 8C 24 A0 00 lea rcx,[rsp+0A0h]
00 00
000000000000018E: 4C 8D 74 24 60 lea r14,[rsp+60h]
0000000000000193: 4C 89 F2 mov rdx,r14
0000000000000196: FF 15 00 00 00 00 call qword ptr [__imp_?task_runner@Thread@base@@QEBA?AV?$scoped_refptr@VSingleThreadTaskRunner@base@@@@XZ]
000000000000019C: 4D 8B 26 mov r12,qword ptr [r14]
000000000000019F: 48 8D 5C 24 78 lea rbx,[rsp+78h]
00000000000001A4: 4C 89 3B mov qword ptr [rbx],r15
00000000000001A7: 48 8D 05 00 00 00 lea rax,[?ExpectSetFlagDeath@?A@base@@YAXPEAVAtomicFlag@1@@Z]
00
00000000000001AE: 48 8D 7C 24 50 lea rdi,[rsp+50h]
00000000000001B3: 48 89 07 mov qword ptr [rdi],rax
00000000000001B6: B9 30 00 00 00 mov ecx,30h
00000000000001BB: E8 00 00 00 00 call ??2@YAPEAX_K@Z
00000000000001C0: 48 89 C6 mov rsi,rax
00000000000001C3: 48 89 5C 24 20 mov qword ptr [rsp+20h],rbx
00000000000001C8: 4C 8D 05 00 00 00 lea r8,[?RunOnce@?$Invoker@U?$BindState@P6AXPEAVAtomicFlag@base@@@ZPEAV12@@internal@base@@$$A6AXXZ@internal@base@@SAXPEAVBindStateBase@23@@Z]
00
00000000000001CF: 48 89 F1 mov rcx,rsi
00000000000001D2: 49 89 F9 mov r9,rdi
00000000000001D5: E8 00 00 00 00 call ??$?0P6AXPEAVAtomicFlag@base@@@ZPEAV01@@?$BindState@P6AXPEAVAtomicFlag@base@@@ZPEAV12@@internal@base@@AEAA@U?$integral_constant@_N$0A@@std@@P6AXXZ$$QEAP6AXPEAVAtomicFlag@2@@Z$$QEAPEAV52@@Z
00000000000001DA: 48 8D 7C 24 58 lea rdi,[rsp+58h]
00000000000001DF: 48 89 F9 mov rcx,rdi
00000000000001E2: 48 89 F2 mov rdx,rsi
00000000000001E5: FF 15 00 00 00 00 call qword ptr [__imp_??0CallbackBase@internal@base@@IEAA@PEAVBindStateBase@12@@Z]
00000000000001EB: FF 15 00 00 00 00 call qword ptr [__imp_?GetProgramCounter@base@@YAPEBXXZ]
00000000000001F1: 48 89 44 24 20 mov qword ptr [rsp+20h],rax
00000000000001F6: 48 8D 15 00 00 00 lea rdx,[??_C@_08BDCFJNKK@TestBody?$AA@]
00
00000000000001FD: 4C 8D 05 00 00 00 lea r8,[??_C@_0DD@CJJFAE@?4?4?1?4?4?1base?1synchronization?1atomi@]
00
0000000000000204: 48 8D 74 24 30 lea rsi,[rsp+30h]
0000000000000209: 41 B9 7F 00 00 00 mov r9d,7Fh
000000000000020F: 48 89 F1 mov rcx,rsi
0000000000000212: FF 15 00 00 00 00 call qword ptr [__imp_??0Location@base@@QEAA@PEBD0HPEBX@Z]
0000000000000218: 4C 89 E1 mov rcx,r12
000000000000021B: 48 89 F2 mov rdx,rsi
000000000000021E: 49 89 F8 mov r8,rdi
0000000000000221: FF 15 00 00 00 00 call qword ptr [__imp_?PostTask@TaskRunner@base@@QEAA_NAEBVLocation@2@V?$OnceCallback@$$A6AXXZ@2@@Z] <----- PostTask
0000000000000227: 4C 89 F1 mov rcx,r14
000000000000022A: E8 00 00 00 00 call ??1?$scoped_refptr@VSingleThreadTaskRunner@base@@@@QEAA@XZ
000000000000022F: 4C 89 F9 mov rcx,r15
0000000000000232: FF 15 00 00 00 00 call qword ptr [__imp_??1AtomicFlag@base@@QEAA@XZ]
0000000000000238: E9 9F 00 00 00 jmp 00000000000002DC
000000000000023D: 48 8D 7C 24 78 lea rdi,[rsp+78h]
0000000000000242: 48 89 F9 mov rcx,rdi
0000000000000245: E8 00 00 00 00 call ??0Message@testing@@QEAA@XZ
000000000000024A: 48 8D 05 00 00 00 lea rax,[??_C@_04LOAJBDKD@true?$AA@]
00
0000000000000251: 48 89 44 24 20 mov qword ptr [rsp+20h],rax
0000000000000256: 4C 8D 05 00 00 00 lea r8,[??_C@_09LMJFDLGP@t?4Start?$CI?$CJ?$AA@]
00
000000000000025D: 4C 8D 0D 00 00 00 lea r9,[??_C@_05LAPONLG@false?$AA@]
00
0000000000000264: 48 8D 54 24 30 lea rdx,[rsp+30h]
0000000000000269: 48 89 F1 mov rcx,rsi
000000000000026C: E8 00 00 00 00 call ?GetBoolAssertionFailureMessage@internal@testing@@YA?AV?$basic_string@DU?$char_traits@D@std@@V?$allocator@D@2@@std@@AEBVAssertionResult@2@PEBD11@Z
0000000000000271: 48 83 BC 24 98 00 cmp qword ptr [rsp+98h],0Fh
00 00 0F
000000000000027A: 48 89 F0 mov rax,rsi
000000000000027D: 76 08 jbe 0000000000000287
000000000000027F: 48 8B 84 24 80 00 mov rax,qword ptr [rsp+80h]
00 00
0000000000000287: 48 89 44 24 20 mov qword ptr [rsp+20h],rax
000000000000028C: 4C 8D 05 00 00 00 lea r8,[??_C@_0DD@CJJFAE@?4?4?1?4?4?1base?1synchronization?1atomi@]
00
0000000000000293: 48 8D 5C 24 70 lea rbx,[rsp+70h]
0000000000000298: BA 02 00 00 00 mov edx,2
000000000000029D: 41 B9 7A 00 00 00 mov r9d,7Ah
00000000000002A3: 48 89 D9 mov rcx,rbx
00000000000002A6: E8 00 00 00 00 call ??0AssertHelper@internal@testing@@QEAA@W4Type@TestPartResult@2@PEBDH1@Z
00000000000002AB: 48 89 D9 mov rcx,rbx
00000000000002AE: 48 89 FA mov rdx,rdi
00000000000002B1: E8 00 00 00 00 call ??4AssertHelper@internal@testing@@QEBAXAEBVMessage@2@@Z
00000000000002B6: 48 89 D9 mov rcx,rbx
00000000000002B9: E8 00 00 00 00 call ??1AssertHelper@internal@testing@@QEAA@XZ
00000000000002BE: 48 89 F1 mov rcx,rsi
00000000000002C1: E8 00 00 00 00 call ??1?$basic_string@DU?$char_traits@D@std@@V?$allocator@D@2@@std@@QEAA@XZ
00000000000002C6: 31 D2 xor edx,edx
00000000000002C8: 48 89 F9 mov rcx,rdi
00000000000002CB: E8 00 00 00 00 call ?reset@?$scoped_ptr@V?$basic_stringstream@DU?$char_traits@D@std@@V?$allocator@D@2@@std@@@internal@testing@@QEAAXPEAV?$basic_stringstream@DU?$char_traits@D@std@@V?$allocator@D@2@@std@@@Z
00000000000002D0: 48 8D 4C 24 38 lea rcx,[rsp+38h]
00000000000002D5: 31 D2 xor edx,edx
00000000000002D7: E8 00 00 00 00 call ?reset@?$scoped_ptr@V?$basic_string@DU?$char_traits@D@std@@V?$allocator@D@2@@std@@@internal@testing@@QEAAXPEAV?$basic_string@DU?$char_traits@D@std@@V?$allocator@D@2@@std@@@Z
00000000000002DC: 48 8D 8C 24 A0 00 lea rcx,[rsp+0A0h]
00 00
00000000000002E4: FF 15 00 00 00 00 call qword ptr [__imp_??1Thread@base@@UEAA@XZ]
00000000000002EA: 48 8B 8C 24 40 01 mov rcx,qword ptr [rsp+140h]
00 00
00000000000002F2: E8 00 00 00 00 call __security_check_cookie
00000000000002F7: 90 nop
00000000000002F8: 48 81 C4 48 01 00 add rsp,148h
00
00000000000002FF: 5B pop rbx
0000000000000300: 5F pop rdi
0000000000000301: 5E pop rsi
0000000000000302: 41 5C pop r12
0000000000000304: 41 5E pop r14
0000000000000306: 41 5F pop r15
0000000000000308: C3 ret
,
Sep 12 2017
Sounds like Fuchsia also see/saw some flakiness in this test: Issue 738275.
,
Sep 12 2017
If it's not a reordering thing, maybe it's something with SequenceChecker..
,
Sep 13 2017
Hey, what about AtomicFlag's destructor.. that's kinda racing with the background thread I think. Yeah, I think that would match what we're seeing.. AtomicFlag's dtor destroys the SequenceCheckerImpl object which means reseting its unique_ptr<SequenceCheckerImpl::Core>..
,
Sep 13 2017
I think this fixes it: https://chromium-review.googlesource.com/665297
,
Sep 13 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/d9c39e66807670dfa584123e84d0206b096eb85b commit d9c39e66807670dfa584123e84d0206b096eb85b Author: Hans Wennborg <hans@chromium.org> Date: Wed Sep 13 20:04:50 2017 Fix race condition in AtomicFlagTest.SetOnDifferentSequenceDeathTest There was a race between destructing 'flag' and running ExpectSetFlagDeath (which refers to 'flag') on the other thread. BUG= 761859 Change-Id: I08e763876f14176b89e741c5f09a25cb10266a73 Reviewed-on: https://chromium-review.googlesource.com/665297 Reviewed-by: Daniel Cheng <dcheng@chromium.org> Commit-Queue: Hans Wennborg <hans@chromium.org> Cr-Commit-Position: refs/heads/master@{#501723} [modify] https://crrev.com/d9c39e66807670dfa584123e84d0206b096eb85b/base/synchronization/atomic_flag_unittest.cc
,
Sep 14 2017
The bot is green now. |
|||
►
Sign in to add a comment |
|||
Comment 1 by h...@chromium.org
, Sep 12 2017