TracedTooManyLines failure in tests/rare/SwizzledLargeApiCorrectness.toml

TracedTooManyLines
Commit: d0c5449d5c785454678370902051e8d2cb850cb6
Command: devRetryCorrectnessTest bin/fdbserver -r simulation -f tests/rare/SwizzledLargeApiCorrectness.toml -s 203426761 -b on --crash --trace_format json

Simulation conf:

startingConfiguration:new backup_worker_enabled:=0 blob_granules_enabled:=0 grv_proxies:=3 log_spill:=2 log_version:=7 perpetual_storage_wiggle:=1 proxies:=3 single remote_single memory-2 storage_migration_type=disabled tenant_mode=optional_experimental usable_regions:=2 regions=[{"datacenters":[{"id":"0","priority":2},{"id":"2","priority":1,"satellite":1}],"satellite_redundancy_mode":"one_satellite_triple"},{"datacenters":[{"id":"1","priority":1},{"id":"3","priority":1,"satellite":1}],"satellite_logs":6,"satellite_redundancy_mode":"one_satellite_triple"}] start
Simulated Cluster Topology:
===========================
zoneId: 1906a23d65874ace8425ddf60f501dcd
  machineId: 1906a23d65874ace8425ddf60f501dcd
    Address: [abcd::3:4:3:4]:1
      Class: test
      Name: Server
zoneId: 238a5ced5f62b1902cf85cee54ea0921
  machineId: 238a5ced5f62b1902cf85cee54ea0921
    Address: [abcd::3:4:3:5]:1
      Class: test
      Name: Server
zoneId: 382e068181ea9ccc0928a97163ff67dc
  machineId: 0516621626466cbff1bef6b584cb578d
    Address: 1.1.1.1:1
      Class: test
      Name: TestSystem
zoneId: 3e0d463030db498db2a7f2eac2a03439
  machineId: 3e0d463030db498db2a7f2eac2a03439
    Address: [abcd::3:4:3:3]:1
      Class: test
      Name: Server
zoneId: 80b64e4d9bab687b695726143d9546ea
  machineId: 80b64e4d9bab687b695726143d9546ea
    Address: [abcd::3:4:3:1]:1
      Class: test
      Name: Server
zoneId: ce7f947fb0f96f0997ed1e47fe7d5c6d
  machineId: ce7f947fb0f96f0997ed1e47fe7d5c6d
    Address: [abcd::3:4:3:6]:1
      Class: test
      Name: Server
zoneId: cecbbd7398bb8cd7a9073636b2c0d938
  machineId: cecbbd7398bb8cd7a9073636b2c0d938
    Address: [abcd::3:4:3:2]:1
      Class: test
      Name: Server
dcId: 0
dataHallId: 0
zoneId: 7d9989343995436dfaa49f3d9c8b5e06
  machineId: 648ea92136a86b6e267377e0ed66e951
    Address: [abcd::2:0:1:0]:1
      Class: unset
      Name: Server
zoneId: e857090d27bc0faea7eec44579b38643
  machineId: 796a6006b1b471095597f6a86d4a0d40
    Address: [abcd::2:0:1:2]:1
      Class: unset
      Name: Server
zoneId: ed0ecf639080438d0d8efd18b38bde90
  machineId: 119a18709d9a723b401e6e9481483fb6
    Address: [abcd::2:0:1:3]:1
      Class: storage_cache
      Name: Server
zoneId: ed596b345277acf1be6a8e103214a723
  machineId: 2dcd80c09d7fb427db0215e5051e967b
    Address: [abcd::2:0:1:1]:1
      Class: storage
      Name: Server
dcId: 1
dataHallId: 1
zoneId: 0e341ea3371d86d76df6d4c0ccd1fe23
  machineId: 3a18755edc0d3f5bed22fd4e9e742c52
    Address: [abcd::2:1:1:0]:1
      Class: storage
      Name: Server
zoneId: 1c6572faaf53d649cb30f7f7816827d2
  machineId: c3c939e7ab3fb77fc81dfa14b96666e6
    Address: [abcd::2:1:1:1]:1
      Class: storage
      Name: Server
zoneId: 932477a810b6d2df8d36c6fdadfd59cc
  machineId: 718e05ef81d28c68c03f198313b5abdf
    Address: [abcd::2:1:1:2]:1
      Class: transaction
      Name: Server
dcId: 2
dataHallId: 2
zoneId: 4f744dcbb8a026f76f77e5fe9e129a8b
  machineId: c88baba3540531824a04d9ee9643c786
    Address: [abcd::2:2:1:2]:1
      Class: transaction
      Name: Server
zoneId: 8bdbfbf2d2a238a2ac1300005a4f38ba
  machineId: c8c2aae50cb78d241aa961f4b1a4c941
    Address: [abcd::2:2:1:1]:1
      Class: transaction
      Name: Server
zoneId: b5476de99c376f60461b9bc132c5ae6c
  machineId: 175b9dff25f48aa321c2804dfd4f9e57
    Address: [abcd::2:2:1:0]:1
      Class: transaction
      Name: Server
dcId: 3
dataHallId: 3
zoneId: 1aaddf74352f4d4421ac5dfef9135d93
  machineId: e754bb465c5aaf122bf5e995c044a3a3
    Address: [abcd::2:3:1:0]:1
      Class: unset
      Name: Server
zoneId: 230a4fdc824092b8d9e5eb48d5ce3f39
  machineId: 0003d44b6965331faf0a673c4ae7dee0
    Address: [abcd::2:3:1:2]:1
      Class: unset
      Name: Server
zoneId: de76f72070f4c4cbd7189cedc1bd1ea6
  machineId: 806cb1d989cc36808e1dc589ace2ea76
    Address: [abcd::2:3:1:1]:1
      Class: unset
      Name: Server

The recovery state is stuck in accepting_commits so that the ConsistencyCheck keep retrying. It seems that the cluster also can't recruit log system in one of the dc. An emergency transaction also changed the original region setting:

{  "Severity": "10", "Time": "49.193427", "DateTime": "2022-06-15T18:24:14Z", "Type": "MasterRecoveryState", "Machine": "[abcd::2:0:1:0]:1", "ID": "6e387025a7f1c65f", "StatusCode": "0", "Status": "reading_coordinated_state", "ThreadID": "11639603881429370873", "LogGroup": "default", "Roles": "CC,CD", "TrackLatestType": "Original" }
{  "Severity": "10", "Time": "51.371700", "DateTime": "2022-06-15T18:24:14Z", "Type": "MasterRecoveryState", "Machine": "[abcd::2:0:1:0]:1", "ID": "6e387025a7f1c65f", "StatusCode": "1", "Status": "locking_coordinated_state", "TLogs": "0", "ActiveGenerations": "1", "MyRecoveryCount": "3", "ForceRecovery": "0", "ThreadID": "11639603881429370873", "LogGroup": "default", "Roles": "CC,CD", "TrackLatestType": "Original" }
{  "Severity": "10", "Time": "52.779701", "DateTime": "2022-06-15T18:24:14Z", "Type": "MasterRecoveryState", "Machine": "[abcd::2:0:1:0]:1", "ID": "6e387025a7f1c65f", "StatusCode": "3", "Status": "reading_transaction_system_state", "ThreadID": "11639603881429370873", "LogGroup": "default", "Roles": "CC,CD", "TrackLatestType": "Original" }
{  "Severity": "10", "Time": "62.779701", "DateTime": "2022-06-15T18:24:14Z", "Type": "MasterRecoveryState", "Machine": "[abcd::2:0:1:0]:1", "ID": "6e387025a7f1c65f", "StatusCode": "5", "Status": "configuration_never_created", "ThreadID": "11639603881429370873", "LogGroup": "default", "Roles": "CC,CD", "TrackLatestType": "Original" }
{  "Severity": "10", "Time": "64.101794", "DateTime": "2022-06-15T18:24:14Z", "Type": "EmergencyTransactionMutation", "Machine": "[abcd::2:0:1:0]:1", "ID": "6e387025a7f1c65f", "MType": "0", "P1": "\\xff/conf/regions", "P2": "\\x01\\x00\\x01b\\xb0\\x00\\xdb\\x0fo\\x01\\x00\\x00{\"regions\":[{\"datacenters\":[{\"id\":\"0\",\"priority\":2},{\"id\":\"2\",\"priority\":1,\"satellite\":1},{\"id\":\"4\",\"priority\":1,\"satellite\":1}],\"satellite_redundancy_mode\":\"two_satellite_fast\"},{\"datacenters\":[{\"id\":\"1\",\"priority\":-1},{\"id\":\"3\",\"priority\":1,\"satellite\":1},{\"id\":\"5\",\"priority\":1,\"satellite\":1,\"satellite_logs\":5}],\"satellite_redundancy_mode\":\"two_satellite_fast\"}]}", "ThreadID": "11639603881429370873", "LogGroup": "default", "Roles": "CC,CD" }
{  "Severity": "10", "Time": "64.101794", "DateTime": "2022-06-15T18:24:14Z", "Type": "MasterRecoveryState", "Machine": "[abcd::2:0:1:0]:1", "ID": "6e387025a7f1c65f", "StatusCode": "7", "Status": "recruiting_transaction_servers", "Conf": "{\"backup_worker_enabled\":0,\"blob_granules_enabled\":0,\"commit_proxies\":4,\"grv_proxies\":2,\"log_spill\":2,\"log_version\":7,\"perpetual_storage_wiggle\":1,\"perpetual_storage_wiggle_locality\":\"data_hall:0\",\"proxies\":6,\"redundancy_mode\":\"single\",\"regions\":[{\"datacenters\":[{\"id\":\"0\",\"priority\":2},{\"id\":\"2\",\"priority\":1,\"satellite\":1},{\"id\":\"4\",\"priority\":1,\"satellite\":1}],\"satellite_redundancy_mode\":\"two_satellite_fast\"},{\"datacenters\":[{\"id\":\"1\",\"priority\":-1},{\"id\":\"3\",\"priority\":1,\"satellite\":1},{\"...", "RequiredCommitProxies": "1", "RequiredGrvProxies": "1", "RequiredResolvers": "1", "ThreadID": "11639603881429370873", "LogGroup": "default", "Roles": "CC,CD", "TrackLatestType": "Original" }
{  "Severity": "10", "Time": "64.101794", "DateTime": "2022-06-15T18:24:14Z", "Type": "MasterRecoveryState", "Machine": "[abcd::2:0:1:0]:1", "ID": "6e387025a7f1c65f", "StatusCode": "8", "Status": "initializing_transaction_servers", "CommitProxies": "2", "GrvProxies": "1", "TLogs": "2", "Resolvers": "1", "SatelliteTLogs": "4", "OldLogRouters": "0", "StorageServers": "1", "BackupWorkers": "0", "PrimaryDcIds": "0", "RemoteDcIds": "1", "ThreadID": "11639603881429370873", "LogGroup": "default", "Roles": "CC,CD", "TrackLatestType": "Original" }
{  "Severity": "10", "Time": "65.675057", "DateTime": "2022-06-15T18:24:14Z", "Type": "EmergencyTransactionMutation", "Machine": "[abcd::2:0:1:0]:1", "ID": "6e387025a7f1c65f", "MType": "0", "P1": "\\xff/conf/regions", "P2": "\\x01\\x00\\x01b\\xb0\\x00\\xdb\\x0fo\\x01\\x00\\x00{\"regions\":[{\"datacenters\":[{\"id\":\"0\",\"priority\":2},{\"id\":\"2\",\"priority\":1,\"satellite\":1},{\"id\":\"4\",\"priority\":1,\"satellite\":1}],\"satellite_redundancy_mode\":\"two_satellite_fast\"},{\"datacenters\":[{\"id\":\"1\",\"priority\":-1},{\"id\":\"3\",\"priority\":1,\"satellite\":1},{\"id\":\"5\",\"priority\":1,\"satellite\":1,\"satellite_logs\":5}],\"satellite_redundancy_mode\":\"two_satellite_fast\"}]}", "ThreadID": "11639603881429370873", "LogGroup": "default", "Roles": "CC,CD,CP,RV,SS" }
{  "Severity": "10", "Time": "66.587923", "DateTime": "2022-06-15T18:24:14Z", "Type": "MasterRecoveryState", "Machine": "[abcd::2:0:1:0]:1", "ID": "6e387025a7f1c65f", "StatusCode": "9", "Status": "recovery_transaction", "PrimaryLocality": "0", "DcId": "0", "ClusterId": "1391ef2ddf642d9d", "ThreadID": "11639603881429370873", "LogGroup": "default", "Roles": "CC,CD,CP,RV,SS,TL", "TrackLatestType": "Original" }
{  "Severity": "10", "Time": "66.587923", "DateTime": "2022-06-15T18:24:14Z", "Type": "MutationRequiresRestart", "Machine": "[abcd::2:0:1:0]:1", "ID": "6e387025a7f1c65f", "M": "code: SetValue param1: \\xff/conf/regions param2: \\x01\\x00\\x01b\\xb0\\x00\\xdb\\x0fo\\x01\\x00\\x00{\"regions\":[{\"datacenters\":[{\"id\":\"0\",\"priority\":2},{\"id\":\"2\",\"priority\":1,\"satellite\":1},{\"id\":\"4\",\"priority\":1,\"satellite\":1}],\"satellite_redundancy_mode\":\"two_satellite_fast\"},{\"datacenters\":[{\"id\":\"1\",\"priority\":-1},{\"id\":\"3\",\"priority\":1,\"satellite\":1},{\"id\":\"5\",\"priority\":1,\"satellite\":1,\"satellite_logs\":5}],\"satellite_redundancy_mode\":\"two_satellite_fast\"}]}", "PrevValue": "(none)", "ToCommit": "0", "ThreadID": "11639603881429370873", "LogGroup": "default", "Roles": "CC,CD,CP,RV,SS,TL" }
{  "Severity": "10", "Time": "68.263413", "DateTime": "2022-06-15T18:24:15Z", "Type": "MasterRecoveryState", "Machine": "[abcd::2:0:1:0]:1", "ID": "6e387025a7f1c65f", "StatusCode": "10", "Status": "writing_coordinated_state", "TLogList": "0: 57ac481d2fc0e3a3799b3c5347395ef7, 3ec14a8aa97ba742ec90d1f0a071c33f 1: f601afe3587c416fe25ffb348ac56468, dd70b710837f89cceac8a064120c6204, dac55ad71a5634608a97b908335a0638, 5f6b8e30097e020bc731c93255e2c1c6 2: 8aaa70699f9dad62b2709a22d6d2a7ed, 8b20d9b5b153f0113ce01a4a42de060e ", "ThreadID": "11639603881429370873", "LogGroup": "default", "Roles": "CC,CD,CP,RV,SS,TL", "TrackLatestType": "Original" }
{  "Severity": "10", "Time": "69.676011", "DateTime": "2022-06-15T18:24:15Z", "Type": "MasterRecoveryState", "Machine": "[abcd::2:0:1:0]:1", "ID": "6e387025a7f1c65f", "StatusCode": "11", "Status": "accepting_commits", "StoreType": "memory-radixtree-beta", "RecoveryDuration": "3.08809", "ThreadID": "11639603881429370873", "LogGroup": "default", "Roles": "CC,CD,CP,RV,SS,TL", "TrackLatestType": "Original" }
{  "Severity": "10", "Time": "69.676011", "DateTime": "2022-06-15T18:24:15Z", "Type": "MasterRecoveryState", "Machine": "[abcd::2:0:1:0]:1", "ID": "6e387025a7f1c65f", "StatusCode": "14", "Status": "fully_recovered", "ClusterId": "1391ef2ddf642d9d", "ThreadID": "11639603881429370873", "LogGroup": "default", "Roles": "CC,CD,CP,RV,SS,TL", "TrackLatestType": "Original" }
{  "Severity": "10", "Time": "271.212108", "DateTime": "2022-06-15T18:24:20Z", "Type": "TrackTlogRecovery", "Machine": "[abcd::2:0:1:0]:1", "ID": "0000000000000000", "FinalUpdate": "0", "NewState.tlogs": "2", "NewState.OldTLogs": "5", "Expected.tlogs": "3", "ThreadID": "11639603881429370873", "LogGroup": "default", "Roles": "CC,CD,CP,RV,SS,TL" }
{  "Severity": "10", "Time": "350.494055", "DateTime": "2022-06-15T18:24:26Z", "Type": "QuietDatabaseWaitingOnFullRecovery", "Machine": "[abcd::3:4:3:3]:1", "ID": "0000000000000000", "ThreadID": "11639603881429370873", "LogGroup": "default", "Roles": "TS" }

apple / foundationdb

TracedTooManyLines failure in tests/rare/SwizzledLargeApiCorrectness.toml #7394