[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:18:29.412503 20546 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.20.16.190:37739
I20260812 06:18:29.413584 20546 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:18:29.414230 20546 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:29.421277 20562 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:29.421277 20557 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:29.421419 20546 server_base.cc:1061] running on GCE node
W20260812 06:18:29.421468 20556 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:29.422060 20546 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:29.422183 20546 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:29.422236 20546 hybrid_clock.cc:648] HybridClock initialized: now 1786515509422232 us; error 0 us; skew 500 ppm
I20260812 06:18:29.424264 20546 webserver.cc:533] Webserver started at http://127.20.16.190:36377/ using document root <none> and password file <none>
I20260812 06:18:29.424877 20546 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:29.424948 20546 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:29.425203 20546 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:29.426935 20546 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/master-0-root/instance:
uuid: "a59eaf6ebd9546b8a475c2f446df137e"
format_stamp: "Formatted at 2026-08-12 06:18:29 on dist-test-slave-x4qh"
I20260812 06:18:29.430852 20546 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:18:29.433146 20575 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:29.434222 20546 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:18:29.434368 20546 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/master-0-root
uuid: "a59eaf6ebd9546b8a475c2f446df137e"
format_stamp: "Formatted at 2026-08-12 06:18:29 on dist-test-slave-x4qh"
I20260812 06:18:29.434482 20546 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:29.452359 20546 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:29.453078 20546 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:18:29.453284 20546 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:29.461527 20672 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.16.190:37739 every 8 connection(s)
I20260812 06:18:29.461532 20546 rpc_server.cc:307] RPC server started. Bound to: 127.20.16.190:37739
I20260812 06:18:29.463966 20673 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:29.469389 20673 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a59eaf6ebd9546b8a475c2f446df137e: Bootstrap starting.
I20260812 06:18:29.471729 20673 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P a59eaf6ebd9546b8a475c2f446df137e: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:29.472589 20673 log.cc:826] T 00000000000000000000000000000000 P a59eaf6ebd9546b8a475c2f446df137e: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:29.474248 20673 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a59eaf6ebd9546b8a475c2f446df137e: No bootstrap required, opened a new log
I20260812 06:18:29.477058 20673 raft_consensus.cc:359] T 00000000000000000000000000000000 P a59eaf6ebd9546b8a475c2f446df137e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a59eaf6ebd9546b8a475c2f446df137e" member_type: VOTER }
I20260812 06:18:29.477229 20673 raft_consensus.cc:385] T 00000000000000000000000000000000 P a59eaf6ebd9546b8a475c2f446df137e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:29.477284 20673 raft_consensus.cc:740] T 00000000000000000000000000000000 P a59eaf6ebd9546b8a475c2f446df137e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a59eaf6ebd9546b8a475c2f446df137e, State: Initialized, Role: FOLLOWER
I20260812 06:18:29.477813 20673 consensus_queue.cc:260] T 00000000000000000000000000000000 P a59eaf6ebd9546b8a475c2f446df137e [NON_LEADER]: Queue going to NON_LEADER mode. State: All replicated index: 0, Majority replicated index: 0, Committed index: 0, Last appended: 0.0, Last appended by leader: 0, Current term: 0, Majority size: -1, State: 0, Mode: NON_LEADER, active raft config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a59eaf6ebd9546b8a475c2f446df137e" member_type: VOTER }
I20260812 06:18:29.477941 20673 raft_consensus.cc:399] T 00000000000000000000000000000000 P a59eaf6ebd9546b8a475c2f446df137e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:29.477986 20673 raft_consensus.cc:493] T 00000000000000000000000000000000 P a59eaf6ebd9546b8a475c2f446df137e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:29.478073 20673 raft_consensus.cc:3060] T 00000000000000000000000000000000 P a59eaf6ebd9546b8a475c2f446df137e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:29.478826 20673 raft_consensus.cc:515] T 00000000000000000000000000000000 P a59eaf6ebd9546b8a475c2f446df137e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a59eaf6ebd9546b8a475c2f446df137e" member_type: VOTER }
I20260812 06:18:29.479205 20673 leader_election.cc:304] T 00000000000000000000000000000000 P a59eaf6ebd9546b8a475c2f446df137e [CANDIDATE]: Term 1 election: Election decided. Result: candidate won. Election summary: received 1 responses out of 1 voters: 1 yes votes; 0 no votes. yes voters: a59eaf6ebd9546b8a475c2f446df137e; no voters: 
I20260812 06:18:29.479498 20673 leader_election.cc:290] T 00000000000000000000000000000000 P a59eaf6ebd9546b8a475c2f446df137e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:29.479650 20685 raft_consensus.cc:2804] T 00000000000000000000000000000000 P a59eaf6ebd9546b8a475c2f446df137e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:29.479921 20685 raft_consensus.cc:697] T 00000000000000000000000000000000 P a59eaf6ebd9546b8a475c2f446df137e [term 1 LEADER]: Becoming Leader. State: Replica: a59eaf6ebd9546b8a475c2f446df137e, State: Running, Role: LEADER
I20260812 06:18:29.480330 20685 consensus_queue.cc:237] T 00000000000000000000000000000000 P a59eaf6ebd9546b8a475c2f446df137e [LEADER]: Queue going to LEADER mode. State: All replicated index: 0, Majority replicated index: 0, Committed index: 0, Last appended: 0.0, Last appended by leader: 0, Current term: 1, Majority size: 1, State: 0, Mode: LEADER, active raft config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a59eaf6ebd9546b8a475c2f446df137e" member_type: VOTER }
I20260812 06:18:29.480592 20673 sys_catalog.cc:565] T 00000000000000000000000000000000 P a59eaf6ebd9546b8a475c2f446df137e [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:29.482295 20691 sys_catalog.cc:455] T 00000000000000000000000000000000 P a59eaf6ebd9546b8a475c2f446df137e [sys.catalog]: SysCatalogTable state changed. Reason: New leader a59eaf6ebd9546b8a475c2f446df137e. Latest consensus state: current_term: 1 leader_uuid: "a59eaf6ebd9546b8a475c2f446df137e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a59eaf6ebd9546b8a475c2f446df137e" member_type: VOTER } }
I20260812 06:18:29.482343 20688 sys_catalog.cc:455] T 00000000000000000000000000000000 P a59eaf6ebd9546b8a475c2f446df137e [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "a59eaf6ebd9546b8a475c2f446df137e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a59eaf6ebd9546b8a475c2f446df137e" member_type: VOTER } }
I20260812 06:18:29.482463 20691 sys_catalog.cc:458] T 00000000000000000000000000000000 P a59eaf6ebd9546b8a475c2f446df137e [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:29.482463 20688 sys_catalog.cc:458] T 00000000000000000000000000000000 P a59eaf6ebd9546b8a475c2f446df137e [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:29.482792 20706 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:29.482986 20546 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:29.485026 20706 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:29.489436 20706 catalog_manager.cc:1383] Generated new cluster ID: f9ecfd015daf4a7db3ec43acc6172314
I20260812 06:18:29.489504 20706 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:29.498068 20706 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:29.498940 20706 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:29.504998 20706 catalog_manager.cc:6092] T 00000000000000000000000000000000 P a59eaf6ebd9546b8a475c2f446df137e: Generated new TSK 0
I20260812 06:18:29.505576 20706 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:29.515991 20546 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:29.518564 20729 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:29.518610 20733 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:29.518923 20546 server_base.cc:1061] running on GCE node
W20260812 06:18:29.518608 20728 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:29.519182 20546 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:29.519234 20546 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:29.519255 20546 hybrid_clock.cc:648] HybridClock initialized: now 1786515509519255 us; error 0 us; skew 500 ppm
I20260812 06:18:29.520284 20546 webserver.cc:533] Webserver started at http://127.20.16.129:44609/ using document root <none> and password file <none>
I20260812 06:18:29.520452 20546 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:29.520509 20546 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:29.520584 20546 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:29.521036 20546 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/instance:
uuid: "c00d888ea113423b9a2f36e6030adff3"
format_stamp: "Formatted at 2026-08-12 06:18:29 on dist-test-slave-x4qh"
I20260812 06:18:29.522877 20546 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:29.524041 20741 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:29.524394 20546 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:29.524485 20546 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root
uuid: "c00d888ea113423b9a2f36e6030adff3"
format_stamp: "Formatted at 2026-08-12 06:18:29 on dist-test-slave-x4qh"
I20260812 06:18:29.524575 20546 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:29.554826 20546 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:29.555339 20546 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:29.555919 20546 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:29.556864 20546 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:29.556944 20546 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:29.557017 20546 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:29.557071 20546 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:29.563877 20546 rpc_server.cc:307] RPC server started. Bound to: 127.20.16.129:36829
I20260812 06:18:29.563918 20863 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.16.129:36829 every 8 connection(s)
I20260812 06:18:29.578228 20864 heartbeater.cc:344] Connected to a master server at 127.20.16.190:37739
I20260812 06:18:29.578500 20864 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:29.578953 20864 heartbeater.cc:507] Master 127.20.16.190:37739 requested a full tablet report, sending...
I20260812 06:18:29.580492 20609 ts_manager.cc:194] Registered new tserver with Master: c00d888ea113423b9a2f36e6030adff3 (127.20.16.129:36829)
I20260812 06:18:29.581372 20546 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.016799427s
I20260812 06:18:29.582099 20609 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:42140
I20260812 06:18:29.591490 20609 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:42150:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:29.606626 20790 tablet_service.cc:1511] Processing CreateTablet for tablet ce85757fc9d94ca394051e269ec86ade (DEFAULT_TABLE table=heavy-update-compaction-test [id=4cf3acc6d3484fac862c2bd07b25ca66]), partition=
I20260812 06:18:29.607095 20790 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet ce85757fc9d94ca394051e269ec86ade. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:29.609114 20883 tablet_bootstrap.cc:492] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Bootstrap starting.
I20260812 06:18:29.610018 20883 tablet_bootstrap.cc:654] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:29.611090 20883 tablet_bootstrap.cc:492] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: No bootstrap required, opened a new log
I20260812 06:18:29.611172 20883 ts_tablet_manager.cc:1403] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:29.611704 20883 raft_consensus.cc:359] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c00d888ea113423b9a2f36e6030adff3" member_type: VOTER last_known_addr { host: "127.20.16.129" port: 36829 } }
I20260812 06:18:29.611869 20883 raft_consensus.cc:385] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:29.611954 20883 raft_consensus.cc:740] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: c00d888ea113423b9a2f36e6030adff3, State: Initialized, Role: FOLLOWER
I20260812 06:18:29.612130 20883 consensus_queue.cc:260] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3 [NON_LEADER]: Queue going to NON_LEADER mode. State: All replicated index: 0, Majority replicated index: 0, Committed index: 0, Last appended: 0.0, Last appended by leader: 0, Current term: 0, Majority size: -1, State: 0, Mode: NON_LEADER, active raft config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c00d888ea113423b9a2f36e6030adff3" member_type: VOTER last_known_addr { host: "127.20.16.129" port: 36829 } }
I20260812 06:18:29.612257 20883 raft_consensus.cc:399] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:29.612313 20883 raft_consensus.cc:493] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:29.612385 20883 raft_consensus.cc:3060] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:29.613241 20883 raft_consensus.cc:515] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c00d888ea113423b9a2f36e6030adff3" member_type: VOTER last_known_addr { host: "127.20.16.129" port: 36829 } }
I20260812 06:18:29.613402 20883 leader_election.cc:304] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3 [CANDIDATE]: Term 1 election: Election decided. Result: candidate won. Election summary: received 1 responses out of 1 voters: 1 yes votes; 0 no votes. yes voters: c00d888ea113423b9a2f36e6030adff3; no voters: 
I20260812 06:18:29.613598 20883 leader_election.cc:290] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:29.613686 20886 raft_consensus.cc:2804] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:29.613909 20886 raft_consensus.cc:697] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3 [term 1 LEADER]: Becoming Leader. State: Replica: c00d888ea113423b9a2f36e6030adff3, State: Running, Role: LEADER
I20260812 06:18:29.614053 20883 ts_tablet_manager.cc:1434] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:29.614081 20886 consensus_queue.cc:237] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3 [LEADER]: Queue going to LEADER mode. State: All replicated index: 0, Majority replicated index: 0, Committed index: 0, Last appended: 0.0, Last appended by leader: 0, Current term: 1, Majority size: 1, State: 0, Mode: LEADER, active raft config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c00d888ea113423b9a2f36e6030adff3" member_type: VOTER last_known_addr { host: "127.20.16.129" port: 36829 } }
I20260812 06:18:29.614464 20864 heartbeater.cc:499] Master 127.20.16.190:37739 was elected leader, sending a full tablet report...
I20260812 06:18:29.616801 20609 catalog_manager.cc:5719] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3 reported cstate change: term changed from 0 to 1, leader changed from <none> to c00d888ea113423b9a2f36e6030adff3 (127.20.16.129). New cstate: current_term: 1 leader_uuid: "c00d888ea113423b9a2f36e6030adff3" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c00d888ea113423b9a2f36e6030adff3" member_type: VOTER last_known_addr { host: "127.20.16.129" port: 36829 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:29.685074 20546 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.059s	user 0.011s	sys 0.016s
I20260812 06:18:29.815124 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushMRSOp(ce85757fc9d94ca394051e269ec86ade): perf score=19.054940
I20260812 06:18:29.992086 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushMRSOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.177s	user 0.140s	sys 0.027s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":220,"delete_count":0,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":316,"dirs.run_wall_time_us":1001,"drs_written":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44980,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":131,"threads_started":1,"update_count":1500}
I20260812 06:18:29.993249 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling LogGCOp(ce85757fc9d94ca394051e269ec86ade): free 20743880 bytes of WAL
I20260812 06:18:29.993546 20747 log_reader.cc:385] T ce85757fc9d94ca394051e269ec86ade: removed 2 log segments from log reader
I20260812 06:18:29.993611 20747 log.cc:1079] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/ce85757fc9d94ca394051e269ec86ade/wal-000000001 (ops 1-6)
I20260812 06:18:29.993741 20747 log.cc:1079] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/ce85757fc9d94ca394051e269ec86ade/wal-000000002 (ops 7-11)
I20260812 06:18:29.999409 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: LogGCOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.006s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:18:29.999832 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=2.188937
I20260812 06:18:30.017181 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.017s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6483,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.017946 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling MajorDeltaCompactionOp(ce85757fc9d94ca394051e269ec86ade): perf score=1.000000
I20260812 06:18:30.169624 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: MajorDeltaCompactionOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.151s	user 0.103s	sys 0.043s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":322,"lbm_read_time_us":9001,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24602,"lbm_writes_lt_1ms":443,"mutex_wait_us":32,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14720,"thread_start_us":354,"threads_started":5,"update_count":2000}
I20260812 06:18:30.170277 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=10.126437
I20260812 06:18:30.211124 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.041s	user 0.017s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17652,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:30.211596 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=2.188937
I20260812 06:18:30.222249 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4054,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.222922 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling UndoDeltaBlockGCOp(ce85757fc9d94ca394051e269ec86ade): 16411394 bytes on disk
I20260812 06:18:30.223672 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: UndoDeltaBlockGCOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":167,"lbm_reads_lt_1ms":4}
I20260812 06:18:30.224105 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling MajorDeltaCompactionOp(ce85757fc9d94ca394051e269ec86ade): perf score=1.000000
I20260812 06:18:30.351118 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: MajorDeltaCompactionOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.127s	user 0.104s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":398,"lbm_read_time_us":10029,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23110,"lbm_writes_lt_1ms":443,"mutex_wait_us":119,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2000}
I20260812 06:18:30.351828 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=10.126437
I20260812 06:18:30.389642 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.038s	user 0.023s	sys 0.011s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15641,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:30.390210 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=2.188937
I20260812 06:18:30.402063 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4048,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.402575 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling MajorDeltaCompactionOp(ce85757fc9d94ca394051e269ec86ade): perf score=1.000000
I20260812 06:18:30.527695 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: MajorDeltaCompactionOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.125s	user 0.094s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":173,"lbm_read_time_us":7963,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27957,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":19,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":22528,"update_count":2000}
I20260812 06:18:30.528280 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=10.126437
I20260812 06:18:30.578545 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.050s	user 0.020s	sys 0.023s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16212,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:30.579191 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=2.188937
I20260812 06:18:30.590492 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4400,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.590917 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling MajorDeltaCompactionOp(ce85757fc9d94ca394051e269ec86ade): perf score=1.000000
I20260812 06:18:30.750118 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: MajorDeltaCompactionOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.159s	user 0.119s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":126,"lbm_read_time_us":12080,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25899,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:18:30.750602 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=10.126437
I20260812 06:18:30.789538 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.039s	user 0.033s	sys 0.004s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17561,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:30.789991 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=2.188937
I20260812 06:18:30.800040 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3972,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.800513 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling MajorDeltaCompactionOp(ce85757fc9d94ca394051e269ec86ade): perf score=1.000000
I20260812 06:18:30.922976 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: MajorDeltaCompactionOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.122s	user 0.086s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1004,"lbm_read_time_us":9337,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23365,"lbm_writes_lt_1ms":443,"mutex_wait_us":314,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":122112,"update_count":2000}
I20260812 06:18:30.923697 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=10.126437
I20260812 06:18:30.967504 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.044s	user 0.023s	sys 0.010s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16943,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:30.968034 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=2.188937
I20260812 06:18:30.979316 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4149,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.980046 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling MajorDeltaCompactionOp(ce85757fc9d94ca394051e269ec86ade): perf score=1.000000
I20260812 06:18:31.106902 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: MajorDeltaCompactionOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.127s	user 0.086s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":288,"lbm_read_time_us":7733,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25441,"lbm_writes_lt_1ms":443,"mutex_wait_us":33,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":65536,"update_count":2000}
I20260812 06:18:31.107659 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=10.126437
I20260812 06:18:31.154249 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.046s	user 0.014s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15191,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:31.154853 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=2.188937
I20260812 06:18:31.165935 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4424,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:31.166419 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushMRSOp(ce85757fc9d94ca394051e269ec86ade): perf score=1.000000
I20260812 06:18:31.208017 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushMRSOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.041s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":96,"dirs.run_cpu_time_us":170,"dirs.run_wall_time_us":1310,"drs_written":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1486,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:31.208813 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling LogGCOp(ce85757fc9d94ca394051e269ec86ade): free 112239310 bytes of WAL
I20260812 06:18:31.209050 20747 log_reader.cc:385] T ce85757fc9d94ca394051e269ec86ade: removed 11 log segments from log reader
I20260812 06:18:31.209096 20747 log.cc:1079] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/ce85757fc9d94ca394051e269ec86ade/wal-000000003 (ops 12-16)
I20260812 06:18:31.209125 20747 log.cc:1079] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/ce85757fc9d94ca394051e269ec86ade/wal-000000004 (ops 17-21)
I20260812 06:18:31.209187 20747 log.cc:1079] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/ce85757fc9d94ca394051e269ec86ade/wal-000000005 (ops 22-26)
I20260812 06:18:31.209233 20747 log.cc:1079] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/ce85757fc9d94ca394051e269ec86ade/wal-000000006 (ops 27-30)
I20260812 06:18:31.209275 20747 log.cc:1079] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/ce85757fc9d94ca394051e269ec86ade/wal-000000007 (ops 31-35)
I20260812 06:18:31.209317 20747 log.cc:1079] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/ce85757fc9d94ca394051e269ec86ade/wal-000000008 (ops 36-40)
I20260812 06:18:31.209357 20747 log.cc:1079] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/ce85757fc9d94ca394051e269ec86ade/wal-000000009 (ops 41-45)
I20260812 06:18:31.209393 20747 log.cc:1079] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/ce85757fc9d94ca394051e269ec86ade/wal-000000010 (ops 46-50)
I20260812 06:18:31.209448 20747 log.cc:1079] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/ce85757fc9d94ca394051e269ec86ade/wal-000000011 (ops 51-55)
I20260812 06:18:31.209478 20747 log.cc:1079] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/ce85757fc9d94ca394051e269ec86ade/wal-000000012 (ops 56-60)
I20260812 06:18:31.209513 20747 log.cc:1079] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/ce85757fc9d94ca394051e269ec86ade/wal-000000013 (ops 61-65)
I20260812 06:18:31.234951 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: LogGCOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.026s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:18:31.235538 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=3.181125
I20260812 06:18:31.253008 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.017s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4531,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:31.253453 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling UndoDeltaBlockGCOp(ce85757fc9d94ca394051e269ec86ade): 447 bytes on disk
I20260812 06:18:31.253875 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: UndoDeltaBlockGCOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:18:31.254323 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=2.188937
I20260812 06:18:31.263993 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3533,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:31.264500 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling MajorDeltaCompactionOp(ce85757fc9d94ca394051e269ec86ade): perf score=1.000000
I20260812 06:18:31.475955 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: MajorDeltaCompactionOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.211s	user 0.165s	sys 0.043s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877329,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1194,"lbm_read_time_us":13088,"lbm_reads_lt_1ms":674,"lbm_write_time_us":38757,"lbm_writes_lt_1ms":643,"mutex_wait_us":416,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3584,"thread_start_us":91,"threads_started":1,"update_count":3000}
I20260812 06:18:31.476725 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=14.095187
I20260812 06:18:31.545145 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.068s	user 0.017s	sys 0.036s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24242,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:31.545665 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=2.188937
I20260812 06:18:31.556027 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4013,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:31.556568 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling MajorDeltaCompactionOp(ce85757fc9d94ca394051e269ec86ade): perf score=1.000000
I20260812 06:18:31.741891 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: MajorDeltaCompactionOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.185s	user 0.130s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":325,"lbm_read_time_us":12741,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31935,"lbm_writes_lt_1ms":543,"mutex_wait_us":68,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":2500}
I20260812 06:18:31.742576 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=14.095187
I20260812 06:18:31.806174 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.063s	user 0.021s	sys 0.040s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":26103,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:31.806720 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=2.188937
I20260812 06:18:31.817688 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4358,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:31.818243 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling MajorDeltaCompactionOp(ce85757fc9d94ca394051e269ec86ade): perf score=1.000000
I20260812 06:18:31.994659 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: MajorDeltaCompactionOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.176s	user 0.122s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":647,"lbm_read_time_us":13227,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30219,"lbm_writes_lt_1ms":543,"mutex_wait_us":318,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:18:31.995185 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=14.095187
I20260812 06:18:32.060417 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.065s	user 0.019s	sys 0.038s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22877,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:32.060900 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=2.188937
I20260812 06:18:32.071888 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4294,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:32.072481 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling MajorDeltaCompactionOp(ce85757fc9d94ca394051e269ec86ade): perf score=1.000000
I20260812 06:18:32.245782 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: MajorDeltaCompactionOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.173s	user 0.124s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":802,"lbm_read_time_us":13249,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29966,"lbm_writes_lt_1ms":543,"mutex_wait_us":283,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16640,"update_count":2500}
I20260812 06:18:32.246551 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=10.126437
I20260812 06:18:32.283733 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.037s	user 0.025s	sys 0.010s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15875,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:32.284243 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=2.188937
I20260812 06:18:32.298770 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5118,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:32.299340 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling MajorDeltaCompactionOp(ce85757fc9d94ca394051e269ec86ade): perf score=1.000000
I20260812 06:18:32.443241 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: MajorDeltaCompactionOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.144s	user 0.110s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":185,"lbm_read_time_us":9450,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28743,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":22144,"update_count":2000}
I20260812 06:18:32.444468 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=10.126437
I20260812 06:18:32.481859 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.037s	user 0.023s	sys 0.011s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15894,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:32.482447 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=2.188937
I20260812 06:18:32.506649 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.024s	user 0.000s	sys 0.011s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5368,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:32.507117 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=2.188937
I20260812 06:18:32.517469 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3920,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:32.518013 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling MajorDeltaCompactionOp(ce85757fc9d94ca394051e269ec86ade): perf score=1.000000
I20260812 06:18:32.670692 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: MajorDeltaCompactionOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.152s	user 0.125s	sys 0.016s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774808,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":583,"lbm_read_time_us":10516,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29080,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15744,"update_count":2500}
I20260812 06:18:32.671203 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=14.095187
I20260812 06:18:32.723035 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.052s	user 0.024s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18075,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:32.723604 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=2.188937
I20260812 06:18:32.735805 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4185,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:32.736462 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushMRSOp(ce85757fc9d94ca394051e269ec86ade): perf score=1.000000
I20260812 06:18:32.769059 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushMRSOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.032s	user 0.026s	sys 0.005s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":188,"dirs.run_wall_time_us":1329,"drs_written":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1934,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:32.769866 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling LogGCOp(ce85757fc9d94ca394051e269ec86ade): free 132571314 bytes of WAL
I20260812 06:18:32.770150 20747 log_reader.cc:385] T ce85757fc9d94ca394051e269ec86ade: removed 13 log segments from log reader
I20260812 06:18:32.770210 20747 log.cc:1079] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/ce85757fc9d94ca394051e269ec86ade/wal-000000014 (ops 66-70)
I20260812 06:18:32.770253 20747 log.cc:1079] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/ce85757fc9d94ca394051e269ec86ade/wal-000000015 (ops 71-75)
I20260812 06:18:32.770287 20747 log.cc:1079] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/ce85757fc9d94ca394051e269ec86ade/wal-000000016 (ops 76-80)
I20260812 06:18:32.770315 20747 log.cc:1079] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/ce85757fc9d94ca394051e269ec86ade/wal-000000017 (ops 81-84)
I20260812 06:18:32.770356 20747 log.cc:1079] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/ce85757fc9d94ca394051e269ec86ade/wal-000000018 (ops 85-89)
I20260812 06:18:32.770381 20747 log.cc:1079] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/ce85757fc9d94ca394051e269ec86ade/wal-000000019 (ops 90-94)
I20260812 06:18:32.770408 20747 log.cc:1079] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/ce85757fc9d94ca394051e269ec86ade/wal-000000020 (ops 95-99)
I20260812 06:18:32.770442 20747 log.cc:1079] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/ce85757fc9d94ca394051e269ec86ade/wal-000000021 (ops 100-104)
I20260812 06:18:32.770471 20747 log.cc:1079] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/ce85757fc9d94ca394051e269ec86ade/wal-000000022 (ops 105-109)
I20260812 06:18:32.770496 20747 log.cc:1079] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/ce85757fc9d94ca394051e269ec86ade/wal-000000023 (ops 110-114)
I20260812 06:18:32.770526 20747 log.cc:1079] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/ce85757fc9d94ca394051e269ec86ade/wal-000000024 (ops 115-119)
I20260812 06:18:32.770555 20747 log.cc:1079] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/ce85757fc9d94ca394051e269ec86ade/wal-000000025 (ops 120-124)
I20260812 06:18:32.770589 20747 log.cc:1079] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/ce85757fc9d94ca394051e269ec86ade/wal-000000026 (ops 125-128)
I20260812 06:18:32.802875 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: LogGCOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.033s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:18:32.803450 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling UndoDeltaBlockGCOp(ce85757fc9d94ca394051e269ec86ade): 483 bytes on disk
I20260812 06:18:32.804054 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: UndoDeltaBlockGCOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:18:32.804705 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=3.181125
I20260812 06:18:32.816798 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4635981,"delete_count":0,"lbm_write_time_us":4979,"lbm_writes_lt_1ms":116,"reinsert_count":0,"update_count":565}
I20260812 06:18:32.817211 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=2.188937
I20260812 06:18:32.827713 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3569330,"delete_count":0,"lbm_write_time_us":3636,"lbm_writes_lt_1ms":90,"reinsert_count":0,"update_count":435}
I20260812 06:18:32.828413 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling MajorDeltaCompactionOp(ce85757fc9d94ca394051e269ec86ade): perf score=1.000000
I20260812 06:18:33.010617 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: MajorDeltaCompactionOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.182s	user 0.129s	sys 0.049s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979742,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":214,"lbm_read_time_us":12392,"lbm_reads_lt_1ms":774,"lbm_write_time_us":36152,"lbm_writes_lt_1ms":743,"mutex_wait_us":3,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3712,"thread_start_us":76,"threads_started":1,"update_count":3500}
I20260812 06:18:33.011844 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=15.087375
I20260812 06:18:33.069530 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.057s	user 0.036s	sys 0.017s Metrics: {"bytes_written":16820145,"delete_count":0,"lbm_write_time_us":24672,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:18:33.070043 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=2.188937
I20260812 06:18:33.080847 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4028,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.081278 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=2.188937
I20260812 06:18:33.094683 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.013s	user 0.004s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5174,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:33.095187 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling MajorDeltaCompactionOp(ce85757fc9d94ca394051e269ec86ade): perf score=1.000000
I20260812 06:18:33.260136 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: MajorDeltaCompactionOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.165s	user 0.125s	sys 0.036s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877209,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":3851,"dirs.run_cpu_time_us":912,"dirs.run_wall_time_us":7377,"lbm_read_time_us":12243,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34343,"lbm_writes_lt_1ms":643,"mutex_wait_us":3175,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:18:33.260860 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=14.095187
I20260812 06:18:33.310774 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.050s	user 0.029s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22023,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:33.311293 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=2.188937
I20260812 06:18:33.327271 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5924,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.328024 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling MajorDeltaCompactionOp(ce85757fc9d94ca394051e269ec86ade): perf score=1.000000
I20260812 06:18:33.496096 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: MajorDeltaCompactionOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.168s	user 0.121s	sys 0.031s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":313,"lbm_read_time_us":10436,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30745,"lbm_writes_lt_1ms":543,"mutex_wait_us":71,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:18:33.496709 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=14.095187
I20260812 06:18:33.561299 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.064s	user 0.039s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":29207,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:18:33.561777 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=2.188937
I20260812 06:18:33.572610 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3979,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.573530 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling MajorDeltaCompactionOp(ce85757fc9d94ca394051e269ec86ade): perf score=1.000000
I20260812 06:18:33.757177 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: MajorDeltaCompactionOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.183s	user 0.127s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":151,"lbm_read_time_us":12266,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28671,"lbm_writes_lt_1ms":543,"mutex_wait_us":37,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":21120,"update_count":2500}
I20260812 06:18:33.757769 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=14.095187
I20260812 06:18:33.809795 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.052s	user 0.029s	sys 0.020s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":23811,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:33.810257 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling MajorDeltaCompactionOp(ce85757fc9d94ca394051e269ec86ade): perf score=1.000000
I20260812 06:18:33.956293 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: MajorDeltaCompactionOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.146s	user 0.100s	sys 0.033s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672161,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":215,"lbm_read_time_us":9169,"lbm_reads_lt_1ms":467,"lbm_write_time_us":23731,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2000}
I20260812 06:18:33.957012 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=14.095187
I20260812 06:18:34.004256 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.047s	user 0.043s	sys 0.001s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20431,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:34.004742 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=2.188937
I20260812 06:18:34.016057 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4226,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:34.017884 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling MajorDeltaCompactionOp(ce85757fc9d94ca394051e269ec86ade): perf score=1.000000
I20260812 06:18:34.209183 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: MajorDeltaCompactionOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.191s	user 0.114s	sys 0.063s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":169,"lbm_read_time_us":12502,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30408,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:18:34.209977 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=14.095187
I20260812 06:18:34.263464 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.053s	user 0.030s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24123,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:18:34.264081 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=2.188937
I20260812 06:18:34.276521 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4691,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:34.277098 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushMRSOp(ce85757fc9d94ca394051e269ec86ade): perf score=1.000000
I20260812 06:18:34.309446 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushMRSOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.032s	user 0.026s	sys 0.004s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":82,"dirs.run_cpu_time_us":254,"dirs.run_wall_time_us":1284,"drs_written":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1854,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:34.310650 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling LogGCOp(ce85757fc9d94ca394051e269ec86ade): free 133024652 bytes of WAL
I20260812 06:18:34.310915 20747 log_reader.cc:385] T ce85757fc9d94ca394051e269ec86ade: removed 13 log segments from log reader
I20260812 06:18:34.311014 20747 log.cc:1079] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/ce85757fc9d94ca394051e269ec86ade/wal-000000027 (ops 129-133)
I20260812 06:18:34.311106 20747 log.cc:1079] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/ce85757fc9d94ca394051e269ec86ade/wal-000000028 (ops 134-138)
I20260812 06:18:34.311167 20747 log.cc:1079] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/ce85757fc9d94ca394051e269ec86ade/wal-000000029 (ops 139-142)
I20260812 06:18:34.311203 20747 log.cc:1079] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/ce85757fc9d94ca394051e269ec86ade/wal-000000030 (ops 143-147)
I20260812 06:18:34.311251 20747 log.cc:1079] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/ce85757fc9d94ca394051e269ec86ade/wal-000000031 (ops 148-152)
I20260812 06:18:34.311327 20747 log.cc:1079] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/ce85757fc9d94ca394051e269ec86ade/wal-000000032 (ops 153-157)
I20260812 06:18:34.311474 20747 log.cc:1079] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/ce85757fc9d94ca394051e269ec86ade/wal-000000033 (ops 158-162)
I20260812 06:18:34.311533 20747 log.cc:1079] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/ce85757fc9d94ca394051e269ec86ade/wal-000000034 (ops 163-167)
I20260812 06:18:34.311568 20747 log.cc:1079] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/ce85757fc9d94ca394051e269ec86ade/wal-000000035 (ops 168-172)
I20260812 06:18:34.311668 20747 log.cc:1079] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/ce85757fc9d94ca394051e269ec86ade/wal-000000036 (ops 173-177)
I20260812 06:18:34.311729 20747 log.cc:1079] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/ce85757fc9d94ca394051e269ec86ade/wal-000000037 (ops 178-182)
I20260812 06:18:34.311762 20747 log.cc:1079] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/ce85757fc9d94ca394051e269ec86ade/wal-000000038 (ops 183-187)
I20260812 06:18:34.311784 20747 log.cc:1079] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/ce85757fc9d94ca394051e269ec86ade/wal-000000039 (ops 188-192)
I20260812 06:18:34.339709 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: LogGCOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.029s	user 0.002s	sys 0.027s Metrics: {}
I20260812 06:18:34.340197 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling UndoDeltaBlockGCOp(ce85757fc9d94ca394051e269ec86ade): 492 bytes on disk
I20260812 06:18:34.341668 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: UndoDeltaBlockGCOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4}
I20260812 06:18:34.342294 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=6.157687
I20260812 06:18:34.370325 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.028s	user 0.012s	sys 0.012s Metrics: {"bytes_written":7876885,"delete_count":0,"lbm_write_time_us":11733,"lbm_writes_lt_1ms":195,"reinsert_count":0,"update_count":960}
I20260812 06:18:34.370901 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling MajorDeltaCompactionOp(ce85757fc9d94ca394051e269ec86ade): perf score=1.000000
I20260812 06:18:34.507184 20546 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.822s	user 1.800s	sys 0.153s
I20260812 06:18:34.577543 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: MajorDeltaCompactionOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.206s	user 0.146s	sys 0.059s Metrics: {"cfile_cache_miss":725,"cfile_cache_miss_bytes":32651439,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"lbm_read_time_us":16248,"lbm_reads_lt_1ms":757,"lbm_write_time_us":37858,"lbm_writes_lt_1ms":735,"peak_mem_usage":86600380,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":3460}
I20260812 06:18:34.578042 20865 maintenance_manager.cc:419] P c00d888ea113423b9a2f36e6030adff3: Scheduling FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade): perf score=11.118625
I20260812 06:18:34.600978 20546 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.093s	user 0.002s	sys 0.000s
I20260812 06:18:34.601640 20546 tablet_server.cc:179] TabletServer@127.20.16.129:0 shutting down...
I20260812 06:18:34.628382 20747 maintenance_manager.cc:643] P c00d888ea113423b9a2f36e6030adff3: FlushDeltaMemStoresOp(ce85757fc9d94ca394051e269ec86ade) complete. Timing: real 0.050s	user 0.031s	sys 0.019s Metrics: {"bytes_written":12635693,"delete_count":0,"lbm_write_time_us":18300,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1540}
I20260812 06:18:34.631088 20546 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:34.631502 20546 tablet_replica.cc:333] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3: stopping tablet replica
I20260812 06:18:34.631732 20546 raft_consensus.cc:2243] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:34.631940 20546 raft_consensus.cc:2272] T ce85757fc9d94ca394051e269ec86ade P c00d888ea113423b9a2f36e6030adff3 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:34.647275 20546 tablet_server.cc:196] TabletServer@127.20.16.129:0 shutdown complete.
I20260812 06:18:34.652290 20546 master.cc:562] Master@127.20.16.190:37739 shutting down...
I20260812 06:18:34.656149 20546 raft_consensus.cc:2243] T 00000000000000000000000000000000 P a59eaf6ebd9546b8a475c2f446df137e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:34.656352 20546 raft_consensus.cc:2272] T 00000000000000000000000000000000 P a59eaf6ebd9546b8a475c2f446df137e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:34.656454 20546 tablet_replica.cc:333] T 00000000000000000000000000000000 P a59eaf6ebd9546b8a475c2f446df137e: stopping tablet replica
I20260812 06:18:34.668795 20546 master.cc:584] Master@127.20.16.190:37739 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5348 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:34.760802 20546 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.20.16.190:46599
I20260812 06:18:34.761209 20546 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:34.763424 20911 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:34.763525 20910 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:34.763792 20916 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:34.764199 20546 server_base.cc:1061] running on GCE node
I20260812 06:18:34.764367 20546 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:34.764405 20546 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:34.764420 20546 hybrid_clock.cc:648] HybridClock initialized: now 1786515514764420 us; error 0 us; skew 500 ppm
I20260812 06:18:34.765221 20546 webserver.cc:533] Webserver started at http://127.20.16.190:35075/ using document root <none> and password file <none>
I20260812 06:18:34.765353 20546 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:34.765395 20546 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:34.765447 20546 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:34.765775 20546 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/master-0-root/instance:
uuid: "7ac67341227d418aabeaaad1f01e88e6"
format_stamp: "Formatted at 2026-08-12 06:18:34 on dist-test-slave-x4qh"
I20260812 06:18:34.767205 20546 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:34.768182 20928 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:34.768415 20546 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:34.768479 20546 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/master-0-root
uuid: "7ac67341227d418aabeaaad1f01e88e6"
format_stamp: "Formatted at 2026-08-12 06:18:34 on dist-test-slave-x4qh"
I20260812 06:18:34.768589 20546 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:34.789448 20546 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:34.789908 20546 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:34.794252 20546 rpc_server.cc:307] RPC server started. Bound to: 127.20.16.190:46599
I20260812 06:18:34.797854 21032 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:34.802340 21031 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.16.190:46599 every 8 connection(s)
I20260812 06:18:34.807463 21032 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7ac67341227d418aabeaaad1f01e88e6: Bootstrap starting.
I20260812 06:18:34.808298 21032 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 7ac67341227d418aabeaaad1f01e88e6: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:34.809476 21032 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7ac67341227d418aabeaaad1f01e88e6: No bootstrap required, opened a new log
I20260812 06:18:34.809942 21032 raft_consensus.cc:359] T 00000000000000000000000000000000 P 7ac67341227d418aabeaaad1f01e88e6 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7ac67341227d418aabeaaad1f01e88e6" member_type: VOTER }
I20260812 06:18:34.810061 21032 raft_consensus.cc:385] T 00000000000000000000000000000000 P 7ac67341227d418aabeaaad1f01e88e6 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:34.810148 21032 raft_consensus.cc:740] T 00000000000000000000000000000000 P 7ac67341227d418aabeaaad1f01e88e6 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7ac67341227d418aabeaaad1f01e88e6, State: Initialized, Role: FOLLOWER
I20260812 06:18:34.810334 21032 consensus_queue.cc:260] T 00000000000000000000000000000000 P 7ac67341227d418aabeaaad1f01e88e6 [NON_LEADER]: Queue going to NON_LEADER mode. State: All replicated index: 0, Majority replicated index: 0, Committed index: 0, Last appended: 0.0, Last appended by leader: 0, Current term: 0, Majority size: -1, State: 0, Mode: NON_LEADER, active raft config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7ac67341227d418aabeaaad1f01e88e6" member_type: VOTER }
I20260812 06:18:34.810434 21032 raft_consensus.cc:399] T 00000000000000000000000000000000 P 7ac67341227d418aabeaaad1f01e88e6 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:34.810494 21032 raft_consensus.cc:493] T 00000000000000000000000000000000 P 7ac67341227d418aabeaaad1f01e88e6 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:34.810554 21032 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 7ac67341227d418aabeaaad1f01e88e6 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:34.811328 21032 raft_consensus.cc:515] T 00000000000000000000000000000000 P 7ac67341227d418aabeaaad1f01e88e6 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7ac67341227d418aabeaaad1f01e88e6" member_type: VOTER }
I20260812 06:18:34.811515 21032 leader_election.cc:304] T 00000000000000000000000000000000 P 7ac67341227d418aabeaaad1f01e88e6 [CANDIDATE]: Term 1 election: Election decided. Result: candidate won. Election summary: received 1 responses out of 1 voters: 1 yes votes; 0 no votes. yes voters: 7ac67341227d418aabeaaad1f01e88e6; no voters: 
I20260812 06:18:34.811736 21032 leader_election.cc:290] T 00000000000000000000000000000000 P 7ac67341227d418aabeaaad1f01e88e6 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:34.811887 21035 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 7ac67341227d418aabeaaad1f01e88e6 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:34.812131 21035 raft_consensus.cc:697] T 00000000000000000000000000000000 P 7ac67341227d418aabeaaad1f01e88e6 [term 1 LEADER]: Becoming Leader. State: Replica: 7ac67341227d418aabeaaad1f01e88e6, State: Running, Role: LEADER
I20260812 06:18:34.812271 21032 sys_catalog.cc:565] T 00000000000000000000000000000000 P 7ac67341227d418aabeaaad1f01e88e6 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:34.812270 21035 consensus_queue.cc:237] T 00000000000000000000000000000000 P 7ac67341227d418aabeaaad1f01e88e6 [LEADER]: Queue going to LEADER mode. State: All replicated index: 0, Majority replicated index: 0, Committed index: 0, Last appended: 0.0, Last appended by leader: 0, Current term: 1, Majority size: 1, State: 0, Mode: LEADER, active raft config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7ac67341227d418aabeaaad1f01e88e6" member_type: VOTER }
I20260812 06:18:34.812815 21039 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7ac67341227d418aabeaaad1f01e88e6 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 7ac67341227d418aabeaaad1f01e88e6. Latest consensus state: current_term: 1 leader_uuid: "7ac67341227d418aabeaaad1f01e88e6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7ac67341227d418aabeaaad1f01e88e6" member_type: VOTER } }
I20260812 06:18:34.812799 21038 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7ac67341227d418aabeaaad1f01e88e6 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "7ac67341227d418aabeaaad1f01e88e6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7ac67341227d418aabeaaad1f01e88e6" member_type: VOTER } }
I20260812 06:18:34.813027 21038 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7ac67341227d418aabeaaad1f01e88e6 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:34.812955 21039 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7ac67341227d418aabeaaad1f01e88e6 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:34.813603 21046 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:34.814455 21046 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:34.814879 20546 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:34.816308 21046 catalog_manager.cc:1383] Generated new cluster ID: 3f4348354462483ebd2847e7ae3a4ab6
I20260812 06:18:34.816380 21046 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:34.841776 21046 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:34.842408 21046 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:34.847568 21046 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 7ac67341227d418aabeaaad1f01e88e6: Generated new TSK 0
I20260812 06:18:34.847757 21046 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:34.879688 20546 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:34.881935 21067 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:34.882007 20546 server_base.cc:1061] running on GCE node
W20260812 06:18:34.882030 21073 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:34.882246 21069 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:34.882442 20546 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:34.882505 20546 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:34.882540 20546 hybrid_clock.cc:648] HybridClock initialized: now 1786515514882539 us; error 0 us; skew 500 ppm
I20260812 06:18:34.883464 20546 webserver.cc:533] Webserver started at http://127.20.16.129:40563/ using document root <none> and password file <none>
I20260812 06:18:34.883647 20546 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:34.883718 20546 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:34.883807 20546 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:34.884241 20546 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/instance:
uuid: "adbd2061e461458496c37d70a30df038"
format_stamp: "Formatted at 2026-08-12 06:18:34 on dist-test-slave-x4qh"
I20260812 06:18:34.885757 20546 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:18:34.886668 21082 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:34.886931 20546 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:34.887025 20546 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root
uuid: "adbd2061e461458496c37d70a30df038"
format_stamp: "Formatted at 2026-08-12 06:18:34 on dist-test-slave-x4qh"
I20260812 06:18:34.887120 20546 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:34.897059 20546 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:34.897440 20546 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:34.897756 20546 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:34.898234 20546 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:34.898298 20546 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:34.898361 20546 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:34.898396 20546 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:34.902611 20546 rpc_server.cc:307] RPC server started. Bound to: 127.20.16.129:33989
I20260812 06:18:34.903136 21184 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.16.129:33989 every 8 connection(s)
I20260812 06:18:34.911860 21185 heartbeater.cc:344] Connected to a master server at 127.20.16.190:46599
I20260812 06:18:34.912011 21185 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:34.912304 21185 heartbeater.cc:507] Master 127.20.16.190:46599 requested a full tablet report, sending...
I20260812 06:18:34.913060 20965 ts_manager.cc:194] Registered new tserver with Master: adbd2061e461458496c37d70a30df038 (127.20.16.129:33989)
I20260812 06:18:34.913467 20546 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.010049303s
I20260812 06:18:34.914033 20965 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:58546
I20260812 06:18:34.921203 20965 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:58562:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:34.930027 21124 tablet_service.cc:1511] Processing CreateTablet for tablet 0204e7e41e0540588324577da3f94148 (DEFAULT_TABLE table=heavy-update-compaction-test [id=f81f0bfea44944bdbcaeeb4ea7405b0c]), partition=
I20260812 06:18:34.930332 21124 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 0204e7e41e0540588324577da3f94148. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:34.933974 21206 tablet_bootstrap.cc:492] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Bootstrap starting.
I20260812 06:18:34.934875 21206 tablet_bootstrap.cc:654] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:34.936328 21206 tablet_bootstrap.cc:492] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: No bootstrap required, opened a new log
I20260812 06:18:34.936457 21206 ts_tablet_manager.cc:1403] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:18:34.936941 21206 raft_consensus.cc:359] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "adbd2061e461458496c37d70a30df038" member_type: VOTER last_known_addr { host: "127.20.16.129" port: 33989 } }
I20260812 06:18:34.937055 21206 raft_consensus.cc:385] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:34.937103 21206 raft_consensus.cc:740] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: adbd2061e461458496c37d70a30df038, State: Initialized, Role: FOLLOWER
I20260812 06:18:34.937264 21206 consensus_queue.cc:260] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038 [NON_LEADER]: Queue going to NON_LEADER mode. State: All replicated index: 0, Majority replicated index: 0, Committed index: 0, Last appended: 0.0, Last appended by leader: 0, Current term: 0, Majority size: -1, State: 0, Mode: NON_LEADER, active raft config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "adbd2061e461458496c37d70a30df038" member_type: VOTER last_known_addr { host: "127.20.16.129" port: 33989 } }
I20260812 06:18:34.937368 21206 raft_consensus.cc:399] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:34.937414 21206 raft_consensus.cc:493] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:34.937471 21206 raft_consensus.cc:3060] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:34.938215 21206 raft_consensus.cc:515] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "adbd2061e461458496c37d70a30df038" member_type: VOTER last_known_addr { host: "127.20.16.129" port: 33989 } }
I20260812 06:18:34.938386 21206 leader_election.cc:304] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038 [CANDIDATE]: Term 1 election: Election decided. Result: candidate won. Election summary: received 1 responses out of 1 voters: 1 yes votes; 0 no votes. yes voters: adbd2061e461458496c37d70a30df038; no voters: 
I20260812 06:18:34.938592 21206 leader_election.cc:290] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:34.938726 21209 raft_consensus.cc:2804] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:34.938978 21209 raft_consensus.cc:697] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038 [term 1 LEADER]: Becoming Leader. State: Replica: adbd2061e461458496c37d70a30df038, State: Running, Role: LEADER
I20260812 06:18:34.938971 21206 ts_tablet_manager.cc:1434] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:18:34.938971 21185 heartbeater.cc:499] Master 127.20.16.190:46599 was elected leader, sending a full tablet report...
I20260812 06:18:34.939184 21209 consensus_queue.cc:237] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038 [LEADER]: Queue going to LEADER mode. State: All replicated index: 0, Majority replicated index: 0, Committed index: 0, Last appended: 0.0, Last appended by leader: 0, Current term: 1, Majority size: 1, State: 0, Mode: LEADER, active raft config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "adbd2061e461458496c37d70a30df038" member_type: VOTER last_known_addr { host: "127.20.16.129" port: 33989 } }
I20260812 06:18:34.940454 20965 catalog_manager.cc:5719] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038 reported cstate change: term changed from 0 to 1, leader changed from <none> to adbd2061e461458496c37d70a30df038 (127.20.16.129). New cstate: current_term: 1 leader_uuid: "adbd2061e461458496c37d70a30df038" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "adbd2061e461458496c37d70a30df038" member_type: VOTER last_known_addr { host: "127.20.16.129" port: 33989 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:35.000066 20546 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.011s	sys 0.012s
I20260812 06:18:35.154026 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushMRSOp(0204e7e41e0540588324577da3f94148): perf score=19.054940
I20260812 06:18:35.317998 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushMRSOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.164s	user 0.121s	sys 0.040s Metrics: {"bytes_written":12717736,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":46,"dirs.run_cpu_time_us":212,"dirs.run_wall_time_us":857,"drs_written":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4,"lbm_write_time_us":43155,"lbm_writes_lt_1ms":767,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1550}
I20260812 06:18:35.318655 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling LogGCOp(0204e7e41e0540588324577da3f94148): free 20743880 bytes of WAL
I20260812 06:18:35.318892 21089 log_reader.cc:385] T 0204e7e41e0540588324577da3f94148: removed 2 log segments from log reader
I20260812 06:18:35.318953 21089 log.cc:1079] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/0204e7e41e0540588324577da3f94148/wal-000000001 (ops 1-6)
I20260812 06:18:35.319043 21089 log.cc:1079] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/0204e7e41e0540588324577da3f94148/wal-000000002 (ops 7-11)
I20260812 06:18:35.323765 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: LogGCOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.005s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:18:35.324153 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling UndoDeltaBlockGCOp(0204e7e41e0540588324577da3f94148): 16411397 bytes on disk
I20260812 06:18:35.324714 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: UndoDeltaBlockGCOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":93,"lbm_reads_lt_1ms":4}
I20260812 06:18:35.325342 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=2.188937
I20260812 06:18:35.345940 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.020s	user 0.011s	sys 0.002s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5614,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:35.346438 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=2.188937
I20260812 06:18:35.357298 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4083,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:35.357726 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling MajorDeltaCompactionOp(0204e7e41e0540588324577da3f94148): perf score=1.000000
I20260812 06:18:35.529510 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: MajorDeltaCompactionOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.172s	user 0.127s	sys 0.031s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":726,"lbm_read_time_us":12141,"lbm_reads_lt_1ms":569,"lbm_write_time_us":28731,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5632,"thread_start_us":315,"threads_started":5,"update_count":2500}
I20260812 06:18:35.530099 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=14.095187
I20260812 06:18:35.580175 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.050s	user 0.022s	sys 0.021s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20088,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:35.580649 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=2.188937
I20260812 06:18:35.590814 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4039,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:35.591246 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling MajorDeltaCompactionOp(0204e7e41e0540588324577da3f94148): perf score=1.000000
I20260812 06:18:35.747516 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: MajorDeltaCompactionOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.156s	user 0.119s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":95,"lbm_read_time_us":11611,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30256,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7168,"update_count":2500}
I20260812 06:18:35.748224 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=10.126437
I20260812 06:18:35.791627 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.043s	user 0.017s	sys 0.026s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18633,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:35.792249 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=2.188937
I20260812 06:18:35.812748 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.020s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6716,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:35.813341 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling MajorDeltaCompactionOp(0204e7e41e0540588324577da3f94148): perf score=1.000000
I20260812 06:18:35.957568 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: MajorDeltaCompactionOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.144s	user 0.104s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":803,"lbm_read_time_us":9373,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24676,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11520,"update_count":2000}
I20260812 06:18:35.958261 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=14.095187
I20260812 06:18:36.019224 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.061s	user 0.019s	sys 0.035s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":21684,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:36.019918 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=2.188937
I20260812 06:18:36.030602 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4272,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:36.031292 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling MajorDeltaCompactionOp(0204e7e41e0540588324577da3f94148): perf score=1.000000
I20260812 06:18:36.217475 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: MajorDeltaCompactionOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.186s	user 0.114s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":3507,"dirs.run_cpu_time_us":552,"dirs.run_wall_time_us":2607,"lbm_read_time_us":13145,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28370,"lbm_writes_lt_1ms":543,"mutex_wait_us":2857,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":28672,"update_count":2500}
I20260812 06:18:36.218246 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=14.095187
I20260812 06:18:36.263886 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.045s	user 0.021s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19944,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:36.264364 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=2.188937
I20260812 06:18:36.276535 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4327,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:36.277166 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling MajorDeltaCompactionOp(0204e7e41e0540588324577da3f94148): perf score=1.000000
I20260812 06:18:36.459874 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: MajorDeltaCompactionOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.182s	user 0.134s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":219,"lbm_read_time_us":11806,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27604,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11776,"update_count":2500}
I20260812 06:18:36.460500 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=14.095187
I20260812 06:18:36.510627 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.050s	user 0.024s	sys 0.015s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19059,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:36.511121 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=2.188937
I20260812 06:18:36.523423 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.012s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4443,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:36.524055 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushMRSOp(0204e7e41e0540588324577da3f94148): perf score=1.000000
I20260812 06:18:36.552562 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushMRSOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.028s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":270,"dirs.run_wall_time_us":1339,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1655,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:36.553150 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling LogGCOp(0204e7e41e0540588324577da3f94148): free 112239257 bytes of WAL
I20260812 06:18:36.553369 21089 log_reader.cc:385] T 0204e7e41e0540588324577da3f94148: removed 11 log segments from log reader
I20260812 06:18:36.553433 21089 log.cc:1079] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/0204e7e41e0540588324577da3f94148/wal-000000003 (ops 12-16)
I20260812 06:18:36.553484 21089 log.cc:1079] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/0204e7e41e0540588324577da3f94148/wal-000000004 (ops 17-20)
I20260812 06:18:36.553542 21089 log.cc:1079] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/0204e7e41e0540588324577da3f94148/wal-000000005 (ops 21-25)
I20260812 06:18:36.553582 21089 log.cc:1079] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/0204e7e41e0540588324577da3f94148/wal-000000006 (ops 26-30)
I20260812 06:18:36.553617 21089 log.cc:1079] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/0204e7e41e0540588324577da3f94148/wal-000000007 (ops 31-35)
I20260812 06:18:36.553655 21089 log.cc:1079] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/0204e7e41e0540588324577da3f94148/wal-000000008 (ops 36-40)
I20260812 06:18:36.553691 21089 log.cc:1079] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/0204e7e41e0540588324577da3f94148/wal-000000009 (ops 41-45)
I20260812 06:18:36.553728 21089 log.cc:1079] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/0204e7e41e0540588324577da3f94148/wal-000000010 (ops 46-50)
I20260812 06:18:36.553764 21089 log.cc:1079] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/0204e7e41e0540588324577da3f94148/wal-000000011 (ops 51-55)
I20260812 06:18:36.553802 21089 log.cc:1079] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/0204e7e41e0540588324577da3f94148/wal-000000012 (ops 56-60)
I20260812 06:18:36.553845 21089 log.cc:1079] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/0204e7e41e0540588324577da3f94148/wal-000000013 (ops 61-65)
I20260812 06:18:36.581790 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: LogGCOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:18:36.582216 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=3.181125
I20260812 06:18:36.609733 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.027s	user 0.013s	sys 0.002s Metrics: {"bytes_written":4512904,"delete_count":0,"lbm_write_time_us":6773,"lbm_writes_lt_1ms":113,"mutex_wait_us":32,"reinsert_count":0,"update_count":550}
I20260812 06:18:36.610208 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling UndoDeltaBlockGCOp(0204e7e41e0540588324577da3f94148): 462 bytes on disk
I20260812 06:18:36.610633 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: UndoDeltaBlockGCOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:18:36.611085 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=2.188937
I20260812 06:18:36.621109 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3724,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:36.621534 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling MajorDeltaCompactionOp(0204e7e41e0540588324577da3f94148): perf score=1.000000
I20260812 06:18:36.871340 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: MajorDeltaCompactionOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.250s	user 0.156s	sys 0.084s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979740,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":773,"lbm_read_time_us":17966,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39815,"lbm_writes_lt_1ms":743,"mutex_wait_us":317,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":66688,"thread_start_us":84,"threads_started":1,"update_count":3500}
I20260812 06:18:36.872337 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=18.063937
I20260812 06:18:36.937573 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.065s	user 0.028s	sys 0.027s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":26360,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:36.938030 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=2.188937
I20260812 06:18:36.949486 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4172,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:36.949952 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling MajorDeltaCompactionOp(0204e7e41e0540588324577da3f94148): perf score=1.000000
I20260812 06:18:37.198446 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: MajorDeltaCompactionOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.248s	user 0.168s	sys 0.079s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":283,"lbm_read_time_us":16036,"lbm_reads_lt_1ms":672,"lbm_write_time_us":47345,"lbm_writes_lt_1ms":643,"mutex_wait_us":24,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16000,"update_count":3000}
I20260812 06:18:37.199007 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=14.095187
I20260812 06:18:37.245229 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.046s	user 0.021s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20961,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:37.246140 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=2.188937
I20260812 06:18:37.266566 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.020s	user 0.004s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7001,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:37.267094 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling MajorDeltaCompactionOp(0204e7e41e0540588324577da3f94148): perf score=1.000000
I20260812 06:18:37.445713 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: MajorDeltaCompactionOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.178s	user 0.132s	sys 0.046s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1028,"lbm_read_time_us":12232,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31379,"lbm_writes_lt_1ms":543,"mutex_wait_us":241,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:18:37.446794 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=14.095187
I20260812 06:18:37.507854 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.061s	user 0.037s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22786,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:37.508648 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=2.188937
I20260812 06:18:37.528043 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.019s	user 0.003s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4891,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:37.528560 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling MajorDeltaCompactionOp(0204e7e41e0540588324577da3f94148): perf score=1.000000
I20260812 06:18:37.712477 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: MajorDeltaCompactionOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.184s	user 0.116s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":307,"lbm_read_time_us":13195,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30823,"lbm_writes_lt_1ms":543,"mutex_wait_us":64,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2500}
I20260812 06:18:37.713100 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=14.095187
I20260812 06:18:37.779428 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.066s	user 0.027s	sys 0.031s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":23086,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:37.779943 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=2.188937
I20260812 06:18:37.790829 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4371,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:37.791312 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling MajorDeltaCompactionOp(0204e7e41e0540588324577da3f94148): perf score=1.000000
I20260812 06:18:37.990574 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: MajorDeltaCompactionOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.199s	user 0.133s	sys 0.054s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":953,"lbm_read_time_us":15207,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32117,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":77568,"update_count":2500}
I20260812 06:18:37.991181 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=14.095187
I20260812 06:18:38.048828 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.057s	user 0.042s	sys 0.014s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21317,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:38.049296 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=2.188937
I20260812 06:18:38.059881 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.010s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4307,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:38.060364 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushMRSOp(0204e7e41e0540588324577da3f94148): perf score=1.000000
I20260812 06:18:38.099040 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushMRSOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.038s	user 0.027s	sys 0.001s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":177,"dirs.run_wall_time_us":1516,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1356,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:38.099874 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling LogGCOp(0204e7e41e0540588324577da3f94148): free 121006488 bytes of WAL
I20260812 06:18:38.100160 21089 log_reader.cc:385] T 0204e7e41e0540588324577da3f94148: removed 12 log segments from log reader
I20260812 06:18:38.100222 21089 log.cc:1079] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/0204e7e41e0540588324577da3f94148/wal-000000014 (ops 66-70)
I20260812 06:18:38.100265 21089 log.cc:1079] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/0204e7e41e0540588324577da3f94148/wal-000000015 (ops 71-75)
I20260812 06:18:38.100288 21089 log.cc:1079] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/0204e7e41e0540588324577da3f94148/wal-000000016 (ops 76-80)
I20260812 06:18:38.100314 21089 log.cc:1079] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/0204e7e41e0540588324577da3f94148/wal-000000017 (ops 81-85)
I20260812 06:18:38.100342 21089 log.cc:1079] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/0204e7e41e0540588324577da3f94148/wal-000000018 (ops 86-90)
I20260812 06:18:38.100366 21089 log.cc:1079] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/0204e7e41e0540588324577da3f94148/wal-000000019 (ops 91-95)
I20260812 06:18:38.100401 21089 log.cc:1079] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/0204e7e41e0540588324577da3f94148/wal-000000020 (ops 96-100)
I20260812 06:18:38.100427 21089 log.cc:1079] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/0204e7e41e0540588324577da3f94148/wal-000000021 (ops 101-104)
I20260812 06:18:38.100450 21089 log.cc:1079] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/0204e7e41e0540588324577da3f94148/wal-000000022 (ops 105-109)
I20260812 06:18:38.100471 21089 log.cc:1079] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/0204e7e41e0540588324577da3f94148/wal-000000023 (ops 110-114)
I20260812 06:18:38.100500 21089 log.cc:1079] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/0204e7e41e0540588324577da3f94148/wal-000000024 (ops 115-119)
I20260812 06:18:38.100529 21089 log.cc:1079] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/0204e7e41e0540588324577da3f94148/wal-000000025 (ops 120-124)
I20260812 06:18:38.131654 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: LogGCOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.032s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:18:38.132046 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling UndoDeltaBlockGCOp(0204e7e41e0540588324577da3f94148): 447 bytes on disk
I20260812 06:18:38.132493 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: UndoDeltaBlockGCOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:18:38.133041 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=2.188937
I20260812 06:18:38.158831 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.026s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4247,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:38.159458 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=2.188937
I20260812 06:18:38.174175 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5748,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:38.174696 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling MajorDeltaCompactionOp(0204e7e41e0540588324577da3f94148): perf score=1.000000
I20260812 06:18:38.406643 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: MajorDeltaCompactionOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.232s	user 0.130s	sys 0.095s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979752,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":761,"lbm_read_time_us":14624,"lbm_reads_lt_1ms":774,"lbm_write_time_us":37517,"lbm_writes_lt_1ms":743,"mutex_wait_us":320,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1920,"thread_start_us":84,"threads_started":1,"update_count":3500}
I20260812 06:18:38.407793 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=18.063937
I20260812 06:18:38.476504 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.068s	user 0.031s	sys 0.024s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":26252,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:38.476987 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=2.188937
I20260812 06:18:38.487293 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3884,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:38.488080 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling MajorDeltaCompactionOp(0204e7e41e0540588324577da3f94148): perf score=1.000000
I20260812 06:18:38.685909 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: MajorDeltaCompactionOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.198s	user 0.117s	sys 0.080s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":899,"lbm_read_time_us":12941,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34508,"lbm_writes_lt_1ms":643,"mutex_wait_us":126,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":14592,"update_count":3000}
I20260812 06:18:38.686549 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=14.095187
I20260812 06:18:38.735905 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.049s	user 0.033s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21445,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:38.736420 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling MajorDeltaCompactionOp(0204e7e41e0540588324577da3f94148): perf score=1.000000
I20260812 06:18:38.883136 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: MajorDeltaCompactionOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.146s	user 0.118s	sys 0.024s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1091,"lbm_read_time_us":9630,"lbm_reads_lt_1ms":463,"lbm_write_time_us":24591,"lbm_writes_lt_1ms":443,"mutex_wait_us":397,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4608,"update_count":2000}
I20260812 06:18:38.883755 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=11.118625
I20260812 06:18:38.932915 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.049s	user 0.021s	sys 0.023s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":19810,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:38.933408 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=2.188937
I20260812 06:18:38.944204 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4201,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:38.944633 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=2.188937
I20260812 06:18:38.957029 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.012s	user 0.002s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5159,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:38.957424 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling MajorDeltaCompactionOp(0204e7e41e0540588324577da3f94148): perf score=1.000000
I20260812 06:18:39.147547 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: MajorDeltaCompactionOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.190s	user 0.124s	sys 0.052s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":142,"lbm_read_time_us":11504,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30723,"lbm_writes_lt_1ms":543,"mutex_wait_us":76,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":25728,"update_count":2500}
I20260812 06:18:39.148306 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=14.095187
I20260812 06:18:39.200214 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.052s	user 0.035s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23895,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:39.200762 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=2.188937
I20260812 06:18:39.213584 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4917,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:39.214108 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling MajorDeltaCompactionOp(0204e7e41e0540588324577da3f94148): perf score=1.000000
I20260812 06:18:39.368535 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: MajorDeltaCompactionOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.154s	user 0.113s	sys 0.035s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":223,"lbm_read_time_us":11435,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28381,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13312,"update_count":2500}
I20260812 06:18:39.369323 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=11.118625
I20260812 06:18:39.419667 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.050s	user 0.028s	sys 0.020s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":20690,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:18:39.420156 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=2.188937
I20260812 06:18:39.431509 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4081,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:39.431988 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=2.188937
I20260812 06:18:39.441589 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.009s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3772,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:39.442021 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling MajorDeltaCompactionOp(0204e7e41e0540588324577da3f94148): perf score=1.000000
I20260812 06:18:39.594789 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: MajorDeltaCompactionOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.153s	user 0.141s	sys 0.008s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":157,"lbm_read_time_us":9338,"lbm_reads_lt_1ms":573,"lbm_write_time_us":33913,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2500}
I20260812 06:18:39.595582 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=11.118625
I20260812 06:18:39.628324 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.033s	user 0.031s	sys 0.001s Metrics: {"bytes_written":12635685,"delete_count":0,"lbm_write_time_us":14436,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1540}
I20260812 06:18:39.628846 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=2.188937
I20260812 06:18:39.643483 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.014s	user 0.007s	sys 0.008s Metrics: {"bytes_written":3774459,"delete_count":0,"lbm_write_time_us":5297,"lbm_writes_lt_1ms":95,"reinsert_count":0,"update_count":460}
I20260812 06:18:39.643970 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushMRSOp(0204e7e41e0540588324577da3f94148): perf score=1.000000
I20260812 06:18:39.679003 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushMRSOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.035s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":137,"dirs.run_cpu_time_us":322,"dirs.run_wall_time_us":1405,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2038,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:39.679811 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling LogGCOp(0204e7e41e0540588324577da3f94148): free 132571575 bytes of WAL
I20260812 06:18:39.680101 21089 log_reader.cc:385] T 0204e7e41e0540588324577da3f94148: removed 13 log segments from log reader
I20260812 06:18:39.680167 21089 log.cc:1079] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/0204e7e41e0540588324577da3f94148/wal-000000026 (ops 125-128)
I20260812 06:18:39.680207 21089 log.cc:1079] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/0204e7e41e0540588324577da3f94148/wal-000000027 (ops 129-133)
I20260812 06:18:39.680239 21089 log.cc:1079] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/0204e7e41e0540588324577da3f94148/wal-000000028 (ops 134-138)
I20260812 06:18:39.680270 21089 log.cc:1079] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/0204e7e41e0540588324577da3f94148/wal-000000029 (ops 139-143)
I20260812 06:18:39.680303 21089 log.cc:1079] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/0204e7e41e0540588324577da3f94148/wal-000000030 (ops 144-148)
I20260812 06:18:39.680338 21089 log.cc:1079] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/0204e7e41e0540588324577da3f94148/wal-000000031 (ops 149-153)
I20260812 06:18:39.680362 21089 log.cc:1079] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/0204e7e41e0540588324577da3f94148/wal-000000032 (ops 154-158)
I20260812 06:18:39.680385 21089 log.cc:1079] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/0204e7e41e0540588324577da3f94148/wal-000000033 (ops 159-163)
I20260812 06:18:39.680414 21089 log.cc:1079] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/0204e7e41e0540588324577da3f94148/wal-000000034 (ops 164-168)
I20260812 06:18:39.680440 21089 log.cc:1079] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/0204e7e41e0540588324577da3f94148/wal-000000035 (ops 169-173)
I20260812 06:18:39.680474 21089 log.cc:1079] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/0204e7e41e0540588324577da3f94148/wal-000000036 (ops 174-178)
I20260812 06:18:39.680506 21089 log.cc:1079] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/0204e7e41e0540588324577da3f94148/wal-000000037 (ops 179-182)
I20260812 06:18:39.680537 21089 log.cc:1079] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: Deleting log segment in path: /tmp/dist-test-taskHWeHt1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515509401689-20546-0/minicluster-data/ts-0-root/wals/0204e7e41e0540588324577da3f94148/wal-000000038 (ops 183-187)
I20260812 06:18:39.712960 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: LogGCOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.033s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:18:39.713419 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling UndoDeltaBlockGCOp(0204e7e41e0540588324577da3f94148): 492 bytes on disk
I20260812 06:18:39.714139 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: UndoDeltaBlockGCOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":104,"lbm_reads_lt_1ms":4}
I20260812 06:18:39.714740 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=5.165500
I20260812 06:18:39.730686 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.016s	user 0.011s	sys 0.003s Metrics: {"bytes_written":6441039,"delete_count":0,"lbm_write_time_us":6948,"lbm_writes_lt_1ms":160,"reinsert_count":0,"update_count":785}
I20260812 06:18:39.731164 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=1.000000
I20260812 06:18:39.746995 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.016s	user 0.004s	sys 0.004s Metrics: {"bytes_written":1764227,"delete_count":0,"lbm_write_time_us":3296,"lbm_writes_lt_1ms":46,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":215}
I20260812 06:18:39.747546 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling MajorDeltaCompactionOp(0204e7e41e0540588324577da3f94148): perf score=1.000000
I20260812 06:18:39.942607 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: MajorDeltaCompactionOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.195s	user 0.133s	sys 0.057s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":479,"lbm_read_time_us":12481,"lbm_reads_lt_1ms":666,"lbm_write_time_us":36076,"lbm_writes_lt_1ms":643,"mutex_wait_us":796,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":72,"threads_started":1,"update_count":3000}
I20260812 06:18:39.943449 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=15.087375
I20260812 06:18:39.994238 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.051s	user 0.033s	sys 0.013s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":22669,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":412,"reinsert_count":0,"update_count":2050}
I20260812 06:18:39.994748 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=2.188937
I20260812 06:18:40.014068 20546 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.014s	user 1.776s	sys 0.201s
I20260812 06:18:40.026042 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.031s	user 0.010s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5436,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:40.026619 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148): perf score=2.188937
I20260812 06:18:40.043535 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: FlushDeltaMemStoresOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.017s	user 0.005s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6747,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":500}
I20260812 06:18:40.044067 21186 maintenance_manager.cc:419] P adbd2061e461458496c37d70a30df038: Scheduling MajorDeltaCompactionOp(0204e7e41e0540588324577da3f94148): perf score=1.000000
I20260812 06:18:40.126235 20546 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.112s	user 0.000s	sys 0.000s
I20260812 06:18:40.126776 20546 tablet_server.cc:179] TabletServer@127.20.16.129:0 shutting down...
I20260812 06:18:40.211501 21089 maintenance_manager.cc:643] P adbd2061e461458496c37d70a30df038: MajorDeltaCompactionOp(0204e7e41e0540588324577da3f94148) complete. Timing: real 0.167s	user 0.110s	sys 0.055s Metrics: {"cfile_cache_hit":250,"cfile_cache_hit_bytes":10177513,"cfile_cache_miss":383,"cfile_cache_miss_bytes":18699693,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1276,"lbm_read_time_us":12729,"lbm_reads_lt_1ms":415,"lbm_write_time_us":29356,"lbm_writes_lt_1ms":643,"mutex_wait_us":327,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":37120,"update_count":3000}
I20260812 06:18:40.212178 20546 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:40.212450 20546 tablet_replica.cc:333] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038: stopping tablet replica
I20260812 06:18:40.212617 20546 raft_consensus.cc:2243] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:40.212795 20546 raft_consensus.cc:2272] T 0204e7e41e0540588324577da3f94148 P adbd2061e461458496c37d70a30df038 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:40.217489 20546 tablet_server.cc:196] TabletServer@127.20.16.129:0 shutdown complete.
I20260812 06:18:40.263803 20546 master.cc:562] Master@127.20.16.190:46599 shutting down...
I20260812 06:18:40.267089 20546 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 7ac67341227d418aabeaaad1f01e88e6 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:40.267306 20546 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 7ac67341227d418aabeaaad1f01e88e6 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:40.267428 20546 tablet_replica.cc:333] T 00000000000000000000000000000000 P 7ac67341227d418aabeaaad1f01e88e6: stopping tablet replica
I20260812 06:18:40.279912 20546 master.cc:584] Master@127.20.16.190:46599 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5611 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10961 ms total)

[----------] Global test environment tear-down
[==========] 2 tests from 1 test suite ran. (10961 ms total)
[  PASSED  ] 2 tests.
