test hs20 WT_ROLLBACK conflict between concurrent operations

Test failure

ERROR: test_hs20.test_hs20.test_hs20(column) (subunit.RemotedTestCase)

test_hs20.test_hs20.test_hs20(column)

----------------------------------------------------------------------

testtools.testresult.real._StringException: Traceback (most recent call last):

  File "/data/mci/d386bda21854dbc3e7a8d455d812839b/wiredtiger/test/suite/test_hs20.py", line 105, in test_hs20

    self.assertEqual(cursor[self.make_key(i)], value1 + "B")

  File "/data/mci/d386bda21854dbc3e7a8d455d812839b/wiredtiger/cmake_build/lang/python/wiredtiger/swig_wiredtiger.py", line 341, in __getitem__

    if self.search() != 0:

_wiredtiger.WiredTigerError: WT_ROLLBACK: conflict between concurrent operations

----------------------------------------------------------------------

Ran 8787 tests in 7473.427s

FAILED (errors=1, skipped=1334)

failure: test_hs20.test_hs20.test_hs20(column) [

Traceback (most recent call last):

  File "/data/mci/d386bda21854dbc3e7a8d455d812839b/wiredtiger/test/suite/wttest.py", line 565, in tearDown

    self.captureout.check(self)

  File "/data/mci/d386bda21854dbc3e7a8d455d812839b/wiredtiger/test/suite/wttest.py", line 116, in check

    testcase.fail('unexpected ' + self.desc + ', contains: "' +

  File "/usr/local/Cellar/python@3.9/3.9.6/Frameworks/Python.framework/Versions/3.9/lib/python3.9/unittest/case.py", line 670, in fail

    raise self.failureException(msg)

AssertionError: unexpected standard output, contains: "[1649995216:991036][5542:0x117d135c0], test_hs20.test_hs20.test_hs20(column), file:test_hs20.wt, WT_CURSOR.search: [WT_VERB_TRANSACTION][NOTICE]: oldest pinned transaction ID rolled back for eviction

[1649995217:36140][5542:0x117d135c0], test_hs20.test_hs20.test_hs20(column), file:test_hs20.wt, WT_CURSOR.search: [WT_VERB_TRANSACTION][NOTICE]: oldest pinned transaction ID rolled back for eviction

[1649995217:58594][5542:0x117d135c0], test_hs20.test_hs20.test_hs20(column), file:test_hs20.wt, WT_CURSOR.search: [WT_VERB_TRANSACTION][NOTICE]: oldest pinned transaction ID rolled back for eviction

[1649995217:81025][5542:0x117d135c0], test_hs20.test_hs20.test_hs20(column), file:test_hs20.wt, WT_CURSOR.search: [WT_VERB_TRANSACTION][NOTICE]: oldest pinned transaction ID rolled back for eviction

[1649995217:103778][5542:0x117d135c0], test_hs20.test_hs20.test_hs20(column), file:test_hs20.wt, WT_CURSOR.search: [WT_VERB_TRANSACTION][NOTICE]: oldest pinned transaction ID rolled back for eviction

[1649995217:146763][5542:0x117d135c0], test_hs20.test_hs20.test_hs20(column), file:test_hs20.wt, WT_CURSOR.search: [WT_VERB_TRANSACTION][NOTICE]: oldest pinned transaction ID rolled back for eviction

[1649995217:189609][5542:0x117d135c0], test_hs20.test_hs20.test_hs20(column), file:test_hs20.wt, WT_CURSOR.search: [WT_VERB_TRANSACTION][NOTICE]: oldest pinned transaction ID rolled back for eviction

[1649995217:233077][5542:0x117d135c0], test_hs20.test_hs20.test_hs20(column), file:test_hs20.wt, WT_CURSOR.search: [WT_VERB_TRANSACTION][NOTICE]: oldest pinned transaction ID rolled back for eviction

[1649995217:275835][5542:0x117d135c0], test_hs20.test_hs20.test_hs20(column), file:test_hs20.wt, WT_CURSOR.search: [WT_VERB_TRANSACTION][NOTICE]: oldest pinned transaction ID rolled back for eviction

[1649995217:318997][5542:0x117d135c0], test_hs20.test_hs20.test_hs20(column), file:test_hs20.wt, WT_CURSOR.search: [WT_VERB_TRANSACTION][NOTICE]: oldest pinned transaction ID rolled back for eviction

"

]

sysctl -n hw.logicalcpu

git rev-parse --show-toplevel

Command failed: command encountered problem: error waiting on process 'ac8f759d-7ee0-4420-bf8b-c999a8a7a07d': exit status 1

Task completed - FAILURE.

Running post-task commands.

Running command 'shell.exec' in "dump stacktraces" (step 1.1 of 5)

`${SHELL_EXPANSION}` syntax will only work for Evergreen expansions. See Evergreen FAQ for details.

# Parse through any failures inside the WT_TEST directory.

python3 ../test/evergreen/print_stack_trace.py --unit_test -e python3 -c WT_TEST -l .

# Look through the stress format directory for any coredumps.

cd test/format

python3 ../../../test/evergreen/print_stack_trace.py --format -e ./t -c . -l .

Finished 'shell.exec' in "dump stacktraces" in 86.26139ms

Running command 's3.put' in "dump stacktraces" (step 1.2 of 5)

Putting files matching filter [wiredtiger/cmake_build/*stacktrace.txt wiredtiger/cmake_build/test/format/*stacktrace.txt] into path wiredtiger/macos-1014/409bb3e3f55079dcd2b51da4e9d28075994604b8/artifacts/ in s3 bucket build_external

performing s3 put to build_external of wiredtiger/macos-1014/409bb3e3f55079dcd2b51da4e9d28075994604b8/artifacts/ [1 of 5]

s3.put: file filter 'wiredtiger/cmake_build/*stacktrace.txt wiredtiger/cmake_build/test/format/*stacktrace.txt' matched no files

Finished 's3.put' in "dump stacktraces" in 177.022243ms

Running command 'shell.exec' in "dump stderr/stdout" (step 2 of 5)

`${SHELL_EXPANSION}` syntax will only work for Evergreen expansions. See Evergreen FAQ for details.

if [ -d "WT_TEST" ]; then

  # Dump stderr/stdout contents generated by the C libraries onto console for Python tests

  find "WT_TEST" -name "std*.txt" ! -empty -exec sh -c "echo 'Contents from {}:'; cat '{}'" \;

fi

Contents from WT_TEST/test_hs20.test_hs20.test_hs20_column/stdout.txt:

[1649995216:991036][5542:0x117d135c0], test_hs20.test_hs20.test_hs20(column), file:test_hs20.wt, WT_CURSOR.search: [WT_VERB_TRANSACTION][NOTICE]: oldest pinned transaction ID rolled back for eviction

[1649995217:36140][5542:0x117d135c0], test_hs20.test_hs20.test_hs20(column), file:test_hs20.wt, WT_CURSOR.search: [WT_VERB_TRANSACTION][NOTICE]: oldest pinned transaction ID rolled back for eviction

[1649995217:58594][5542:0x117d135c0], test_hs20.test_hs20.test_hs20(column), file:test_hs20.wt, WT_CURSOR.search: [WT_VERB_TRANSACTION][NOTICE]: oldest pinned transaction ID rolled back for eviction

[1649995217:81025][5542:0x117d135c0], test_hs20.test_hs20.test_hs20(column), file:test_hs20.wt, WT_CURSOR.search: [WT_VERB_TRANSACTION][NOTICE]: oldest pinned transaction ID rolled back for eviction

[1649995217:103778][5542:0x117d135c0], test_hs20.test_hs20.test_hs20(column), file:test_hs20.wt, WT_CURSOR.search: [WT_VERB_TRANSACTION][NOTICE]: oldest pinned transaction ID rolled back for eviction

[1649995217:146763][5542:0x117d135c0], test_hs20.test_hs20.test_hs20(column), file:test_hs20.wt, WT_CURSOR.search: [WT_VERB_TRANSACTION][NOTICE]: oldest pinned transaction ID rolled back for eviction

[1649995217:189609][5542:0x117d135c0], test_hs20.test_hs20.test_hs20(column), file:test_hs20.wt, WT_CURSOR.search: [WT_VERB_TRANSACTION][NOTICE]: oldest pinned transaction ID rolled back for eviction

[1649995217:233077][5542:0x117d135c0], test_hs20.test_hs20.test_hs20(column), file:test_hs20.wt, WT_CURSOR.search: [WT_VERB_TRANSACTION][NOTICE]: oldest pinned transaction ID rolled back for eviction

[1649995217:275835][5542:0x117d135c0], test_hs20.test_hs20.test_hs20(column), file:test_hs20.wt, WT_CURSOR.search: [WT_VERB_TRANSACTION][NOTICE]: oldest pinned transaction ID rolled back for eviction

[1649995217:318997][5542:0x117d135c0], test_hs20.test_hs20.test_hs20(column), file:test_hs20.wt, WT_CURSOR.search: [WT_VERB_TRANSACTION][NOTICE]: oldest pinned transaction ID rolled back for eviction

Finished 'shell.exec' in "dump stderr/stdout" in 10.100076ms

Running command 'archive.targz_pack' in "upload artifact" (step 3.1 of 5)

Finished 'archive.targz_pack' in "upload artifact" in 7.087757922s

Running command 's3.put' in "upload artifact" (step 3.2 of 5)

Putting wiredtiger.tgz into build_external/wiredtiger/macos-1014/409bb3e3f55079dcd2b51da4e9d28075994604b8/artifacts/unit-test_wiredtiger_macos_1014_409bb3e3f55079dcd2b51da4e9d28075994604b8_22_04_15_01_32_49-0.tgz (https://build_external.s3.amazonaws.com/wiredtiger/macos-1014/409bb3e3f55079dcd2b51da4e9d28075994604b8/artifacts/unit-test_wiredtiger_macos_1014_409bb3e3f55079dcd2b51da4e9d28075994604b8_22_04_15_01_32_49-0.tgz)

performing s3 put to build_external of wiredtiger/macos-1014/409bb3e3f55079dcd2b51da4e9d28075994604b8/artifacts/unit-test_wiredtiger_macos_1014_409bb3e3f55079dcd2b51da4e9d28075994604b8_22_04_15_01_32_49-0.tgz [1 of 5]

Finished 's3.put' in "upload artifact" in 10.198526894s

Running command 'archive.targz_pack' in "save wt hang analyzer core/debugger files" (step 4.1 of 5)

Finished 'archive.targz_pack' in "save wt hang analyzer core/debugger files" in 32.783725ms

Running command 's3.put' in "save wt hang analyzer core/debugger files" (step 4.2 of 5)

Putting wt-hang-analyzer.tgz into build_external/wiredtiger/macos-1014/409bb3e3f55079dcd2b51da4e9d28075994604b8/wt_hang_analyzer/wt-hang-analyzer_unit-test_wiredtiger_macos_1014_409bb3e3f55079dcd2b51da4e9d28075994604b8_22_04_15_01_32_49-0.tgz (https://build_external.s3.amazonaws.com/wiredtiger/macos-1014/409bb3e3f55079dcd2b51da4e9d28075994604b8/wt_hang_analyzer/wt-hang-analyzer_unit-test_wiredtiger_macos_1014_409bb3e3f55079dcd2b51da4e9d28075994604b8_22_04_15_01_32_49-0.tgz)

performing s3 put to build_external of wiredtiger/macos-1014/409bb3e3f55079dcd2b51da4e9d28075994604b8/wt_hang_analyzer/wt-hang-analyzer_unit-test_wiredtiger_macos_1014_409bb3e3f55079dcd2b51da4e9d28075994604b8_22_04_15_01_32_49-0.tgz [1 of 5]

file '/data/mci/d386bda21854dbc3e7a8d455d812839b/wt-hang-analyzer.tgz' not found but skip missing true

Finished 's3.put' in "save wt hang analyzer core/debugger files" in 74.997232ms

Running command 'shell.exec' in "cleanup" (step 5 of 5)

`${SHELL_EXPANSION}` syntax will only work for Evergreen expansions. See Evergreen FAQ for details.

Finished 'shell.exec' in "cleanup" in 282.120403ms

[message='Finished running post-task commands.' total_time='17.967933534s']

Link: https://evergreen.mongodb.com/task_log_raw/wiredtiger_macos_1014_unit_test_409bb3e3f55079dcd2b51da4e9d28075994604b8_22_04_15_01_32_49/0?type=T#L31437