[==========] 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:20:04.155810 10160 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.9.236.62:38917
I20260812 06:20:04.157141 10160 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:20:04.157903 10160 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:04.165822 10175 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:20:04.165772 10171 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:20:04.166142 10160 server_base.cc:1061] running on GCE node
W20260812 06:20:04.166213 10169 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:20:04.166975 10160 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:04.167182 10160 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:20:04.167243 10160 hybrid_clock.cc:648] HybridClock initialized: now 1786515604167240 us; error 0 us; skew 500 ppm
I20260812 06:20:04.169739 10160 webserver.cc:533] Webserver started at http://127.9.236.62:39119/ using document root <none> and password file <none>
I20260812 06:20:04.170495 10160 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:04.170567 10160 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:04.170874 10160 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:04.173012 10160 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/master-0-root/instance:
uuid: "92e0b45bab2b40cb82c33ecd93baf246"
format_stamp: "Formatted at 2026-08-12 06:20:04 on dist-test-slave-h3ft"
I20260812 06:20:04.177482 10160 fs_manager.cc:696] Time spent creating directory manager: real 0.004s	user 0.005s	sys 0.000s
I20260812 06:20:04.180049 10181 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:20:04.181262 10160 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:20:04.181419 10160 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/master-0-root
uuid: "92e0b45bab2b40cb82c33ecd93baf246"
format_stamp: "Formatted at 2026-08-12 06:20:04 on dist-test-slave-h3ft"
I20260812 06:20:04.181569 10160 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-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:20:04.208520 10160 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:04.209393 10160 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:20:04.209622 10160 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:04.219280 10160 rpc_server.cc:307] RPC server started. Bound to: 127.9.236.62:38917
I20260812 06:20:04.219298 10257 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.9.236.62:38917 every 8 connection(s)
I20260812 06:20:04.222218 10258 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:20:04.228555 10258 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 92e0b45bab2b40cb82c33ecd93baf246: Bootstrap starting.
I20260812 06:20:04.231441 10258 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 92e0b45bab2b40cb82c33ecd93baf246: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:04.232558 10258 log.cc:826] T 00000000000000000000000000000000 P 92e0b45bab2b40cb82c33ecd93baf246: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:04.234604 10258 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 92e0b45bab2b40cb82c33ecd93baf246: No bootstrap required, opened a new log
I20260812 06:20:04.237716 10258 raft_consensus.cc:359] T 00000000000000000000000000000000 P 92e0b45bab2b40cb82c33ecd93baf246 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "92e0b45bab2b40cb82c33ecd93baf246" member_type: VOTER }
I20260812 06:20:04.237929 10258 raft_consensus.cc:385] T 00000000000000000000000000000000 P 92e0b45bab2b40cb82c33ecd93baf246 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:04.237977 10258 raft_consensus.cc:740] T 00000000000000000000000000000000 P 92e0b45bab2b40cb82c33ecd93baf246 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 92e0b45bab2b40cb82c33ecd93baf246, State: Initialized, Role: FOLLOWER
I20260812 06:20:04.238611 10258 consensus_queue.cc:260] T 00000000000000000000000000000000 P 92e0b45bab2b40cb82c33ecd93baf246 [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: "92e0b45bab2b40cb82c33ecd93baf246" member_type: VOTER }
I20260812 06:20:04.238766 10258 raft_consensus.cc:399] T 00000000000000000000000000000000 P 92e0b45bab2b40cb82c33ecd93baf246 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:04.238817 10258 raft_consensus.cc:493] T 00000000000000000000000000000000 P 92e0b45bab2b40cb82c33ecd93baf246 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:04.238925 10258 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 92e0b45bab2b40cb82c33ecd93baf246 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:04.239840 10258 raft_consensus.cc:515] T 00000000000000000000000000000000 P 92e0b45bab2b40cb82c33ecd93baf246 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "92e0b45bab2b40cb82c33ecd93baf246" member_type: VOTER }
I20260812 06:20:04.240290 10258 leader_election.cc:304] T 00000000000000000000000000000000 P 92e0b45bab2b40cb82c33ecd93baf246 [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: 92e0b45bab2b40cb82c33ecd93baf246; no voters: 
I20260812 06:20:04.240593 10258 leader_election.cc:290] T 00000000000000000000000000000000 P 92e0b45bab2b40cb82c33ecd93baf246 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:04.240767 10263 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 92e0b45bab2b40cb82c33ecd93baf246 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:04.241055 10263 raft_consensus.cc:697] T 00000000000000000000000000000000 P 92e0b45bab2b40cb82c33ecd93baf246 [term 1 LEADER]: Becoming Leader. State: Replica: 92e0b45bab2b40cb82c33ecd93baf246, State: Running, Role: LEADER
I20260812 06:20:04.241537 10263 consensus_queue.cc:237] T 00000000000000000000000000000000 P 92e0b45bab2b40cb82c33ecd93baf246 [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: "92e0b45bab2b40cb82c33ecd93baf246" member_type: VOTER }
I20260812 06:20:04.241850 10258 sys_catalog.cc:565] T 00000000000000000000000000000000 P 92e0b45bab2b40cb82c33ecd93baf246 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:04.243817 10268 sys_catalog.cc:455] T 00000000000000000000000000000000 P 92e0b45bab2b40cb82c33ecd93baf246 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 92e0b45bab2b40cb82c33ecd93baf246. Latest consensus state: current_term: 1 leader_uuid: "92e0b45bab2b40cb82c33ecd93baf246" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "92e0b45bab2b40cb82c33ecd93baf246" member_type: VOTER } }
I20260812 06:20:04.243801 10265 sys_catalog.cc:455] T 00000000000000000000000000000000 P 92e0b45bab2b40cb82c33ecd93baf246 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "92e0b45bab2b40cb82c33ecd93baf246" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "92e0b45bab2b40cb82c33ecd93baf246" member_type: VOTER } }
I20260812 06:20:04.243978 10265 sys_catalog.cc:458] T 00000000000000000000000000000000 P 92e0b45bab2b40cb82c33ecd93baf246 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:04.243978 10268 sys_catalog.cc:458] T 00000000000000000000000000000000 P 92e0b45bab2b40cb82c33ecd93baf246 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:04.244491 10160 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:04.244691 10287 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:04.247398 10287 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:04.253386 10287 catalog_manager.cc:1383] Generated new cluster ID: 1097487145504d9e93406b776f8d8c9f
I20260812 06:20:04.253465 10287 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:04.284049 10287 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:04.285169 10287 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:04.296725 10287 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 92e0b45bab2b40cb82c33ecd93baf246: Generated new TSK 0
I20260812 06:20:04.297794 10287 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:04.309911 10160 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:04.313791 10299 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:20:04.313903 10293 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:20:04.314006 10295 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:20:04.314178 10160 server_base.cc:1061] running on GCE node
I20260812 06:20:04.314401 10160 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:04.314463 10160 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:20:04.314498 10160 hybrid_clock.cc:648] HybridClock initialized: now 1786515604314497 us; error 0 us; skew 500 ppm
I20260812 06:20:04.315754 10160 webserver.cc:533] Webserver started at http://127.9.236.1:34451/ using document root <none> and password file <none>
I20260812 06:20:04.315974 10160 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:04.316061 10160 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:04.316164 10160 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:04.316658 10160 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root/instance:
uuid: "055d9136d44b4b31a2525e0607c56a0e"
format_stamp: "Formatted at 2026-08-12 06:20:04 on dist-test-slave-h3ft"
I20260812 06:20:04.318485 10160 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.001s
I20260812 06:20:04.319751 10309 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:20:04.320021 10160 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:04.320101 10160 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root
uuid: "055d9136d44b4b31a2525e0607c56a0e"
format_stamp: "Formatted at 2026-08-12 06:20:04 on dist-test-slave-h3ft"
I20260812 06:20:04.320204 10160 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-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:20:04.348773 10160 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:04.349377 10160 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:04.350049 10160 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:04.351228 10160 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:04.351287 10160 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:04.351379 10160 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:04.351421 10160 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:04.360239 10160 rpc_server.cc:307] RPC server started. Bound to: 127.9.236.1:37383
I20260812 06:20:04.360257 10408 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.9.236.1:37383 every 8 connection(s)
I20260812 06:20:04.378470 10409 heartbeater.cc:344] Connected to a master server at 127.9.236.62:38917
I20260812 06:20:04.378831 10409 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:04.379568 10409 heartbeater.cc:507] Master 127.9.236.62:38917 requested a full tablet report, sending...
I20260812 06:20:04.381570 10203 ts_manager.cc:194] Registered new tserver with Master: 055d9136d44b4b31a2525e0607c56a0e (127.9.236.1:37383)
I20260812 06:20:04.382339 10160 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.021240842s
I20260812 06:20:04.383347 10203 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:37288
I20260812 06:20:04.394583 10203 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:37290:
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:20:04.412477 10359 tablet_service.cc:1511] Processing CreateTablet for tablet d97df3a0ac3946d084d6b12d3f52631a (DEFAULT_TABLE table=heavy-update-compaction-test [id=51741804bc8d442c97981b66fec7bbe4]), partition=
I20260812 06:20:04.413105 10359 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet d97df3a0ac3946d084d6b12d3f52631a. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:04.416211 10426 tablet_bootstrap.cc:492] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Bootstrap starting.
I20260812 06:20:04.417721 10426 tablet_bootstrap.cc:654] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:04.419224 10426 tablet_bootstrap.cc:492] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: No bootstrap required, opened a new log
I20260812 06:20:04.419345 10426 ts_tablet_manager.cc:1403] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:20:04.419992 10426 raft_consensus.cc:359] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "055d9136d44b4b31a2525e0607c56a0e" member_type: VOTER last_known_addr { host: "127.9.236.1" port: 37383 } }
I20260812 06:20:04.420115 10426 raft_consensus.cc:385] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:04.420140 10426 raft_consensus.cc:740] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 055d9136d44b4b31a2525e0607c56a0e, State: Initialized, Role: FOLLOWER
I20260812 06:20:04.420301 10426 consensus_queue.cc:260] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e [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: "055d9136d44b4b31a2525e0607c56a0e" member_type: VOTER last_known_addr { host: "127.9.236.1" port: 37383 } }
I20260812 06:20:04.420382 10426 raft_consensus.cc:399] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:04.420428 10426 raft_consensus.cc:493] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:04.420488 10426 raft_consensus.cc:3060] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:04.421434 10426 raft_consensus.cc:515] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "055d9136d44b4b31a2525e0607c56a0e" member_type: VOTER last_known_addr { host: "127.9.236.1" port: 37383 } }
I20260812 06:20:04.421609 10426 leader_election.cc:304] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e [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: 055d9136d44b4b31a2525e0607c56a0e; no voters: 
I20260812 06:20:04.421878 10426 leader_election.cc:290] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:04.422073 10430 raft_consensus.cc:2804] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:04.422283 10426 ts_tablet_manager.cc:1434] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:20:04.422412 10430 raft_consensus.cc:697] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e [term 1 LEADER]: Becoming Leader. State: Replica: 055d9136d44b4b31a2525e0607c56a0e, State: Running, Role: LEADER
I20260812 06:20:04.422658 10409 heartbeater.cc:499] Master 127.9.236.62:38917 was elected leader, sending a full tablet report...
I20260812 06:20:04.422863 10430 consensus_queue.cc:237] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e [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: "055d9136d44b4b31a2525e0607c56a0e" member_type: VOTER last_known_addr { host: "127.9.236.1" port: 37383 } }
I20260812 06:20:04.426633 10203 catalog_manager.cc:5719] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e reported cstate change: term changed from 0 to 1, leader changed from <none> to 055d9136d44b4b31a2525e0607c56a0e (127.9.236.1). New cstate: current_term: 1 leader_uuid: "055d9136d44b4b31a2525e0607c56a0e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "055d9136d44b4b31a2525e0607c56a0e" member_type: VOTER last_known_addr { host: "127.9.236.1" port: 37383 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:04.500952 10160 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.066s	user 0.018s	sys 0.008s
I20260812 06:20:04.611760 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushMRSOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=10.125253
I20260812 06:20:04.761636 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushMRSOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.149s	user 0.106s	sys 0.032s Metrics: {"bytes_written":8205082,"cfile_init":1,"compiler_manager_pool.queue_time_us":336,"delete_count":0,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":268,"dirs.run_wall_time_us":897,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":32140,"lbm_writes_lt_1ms":457,"peak_mem_usage":0,"reinsert_count":0,"rows_written":102,"thread_start_us":190,"threads_started":1,"update_count":1000}
I20260812 06:20:04.763451 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling LogGCOp(d97df3a0ac3946d084d6b12d3f52631a): free 8725963 bytes of WAL
I20260812 06:20:04.763919 10314 log_reader.cc:385] T d97df3a0ac3946d084d6b12d3f52631a: removed 1 log segments from log reader
I20260812 06:20:04.764011 10314 log.cc:1079] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/d97df3a0ac3946d084d6b12d3f52631a/wal-000000001 (ops 1-6)
I20260812 06:20:04.766916 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: LogGCOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:20:04.767452 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=2.188937
I20260812 06:20:04.784940 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.017s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6307,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.785634 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling UndoDeltaBlockGCOp(d97df3a0ac3946d084d6b12d3f52631a): 8206538 bytes on disk
I20260812 06:20:04.786572 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: UndoDeltaBlockGCOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":141,"lbm_reads_lt_1ms":4}
I20260812 06:20:04.787185 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=1.000000
I20260812 06:20:04.947644 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.160s	user 0.112s	sys 0.029s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16487939,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":772,"lbm_read_time_us":9940,"lbm_reads_lt_1ms":360,"lbm_write_time_us":26282,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":2176,"thread_start_us":435,"threads_started":5,"update_count":1500}
I20260812 06:20:04.948258 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=10.126437
I20260812 06:20:04.993134 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.045s	user 0.010s	sys 0.028s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":18364,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:04.993757 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=1.000000
I20260812 06:20:05.134263 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.140s	user 0.109s	sys 0.028s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16487819,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":112,"lbm_read_time_us":11284,"lbm_reads_lt_1ms":363,"lbm_write_time_us":22911,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:20:05.135041 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=10.126437
I20260812 06:20:05.172775 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.038s	user 0.023s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17136,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:05.173328 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=2.188937
I20260812 06:20:05.187537 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.014s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5522,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.188165 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=1.000000
I20260812 06:20:05.326526 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.138s	user 0.101s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1199,"lbm_read_time_us":10790,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26796,"lbm_writes_lt_1ms":443,"mutex_wait_us":408,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15488,"update_count":2000}
I20260812 06:20:05.327191 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=10.126437
I20260812 06:20:05.382404 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.055s	user 0.019s	sys 0.025s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":22273,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:05.383173 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=2.188937
I20260812 06:20:05.396135 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.013s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4929,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.397058 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=1.000000
I20260812 06:20:05.544559 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.147s	user 0.123s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":171,"lbm_read_time_us":11886,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29494,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12928,"update_count":2000}
I20260812 06:20:05.545334 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=10.126437
I20260812 06:20:05.591732 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.046s	user 0.024s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20973,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:05.592458 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=2.188937
I20260812 06:20:05.607300 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5046,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.608109 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=1.000000
I20260812 06:20:05.766386 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.158s	user 0.134s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":300,"lbm_read_time_us":11200,"lbm_reads_lt_1ms":472,"lbm_write_time_us":33485,"lbm_writes_lt_1ms":443,"mutex_wait_us":96,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:20:05.766979 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=10.126437
I20260812 06:20:05.829919 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.063s	user 0.021s	sys 0.028s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18709,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:05.830780 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=2.188937
I20260812 06:20:05.844551 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.013s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5168,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.845176 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=1.000000
I20260812 06:20:06.020228 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.175s	user 0.123s	sys 0.043s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590348,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":208,"lbm_read_time_us":15155,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26203,"lbm_writes_lt_1ms":443,"mutex_wait_us":38,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:20:06.021051 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=10.126437
I20260812 06:20:06.083946 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.062s	user 0.037s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":24123,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":1500}
I20260812 06:20:06.084578 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=2.188937
I20260812 06:20:06.097959 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.013s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4754,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:06.098749 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=1.000000
I20260812 06:20:06.256707 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.158s	user 0.131s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":182,"lbm_read_time_us":12648,"lbm_reads_lt_1ms":472,"lbm_write_time_us":31115,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":2000}
I20260812 06:20:06.257655 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=10.126437
I20260812 06:20:06.307466 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.050s	user 0.036s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20836,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:06.308149 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=2.188937
I20260812 06:20:06.322012 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.014s	user 0.012s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4792,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:06.322662 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushMRSOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=1.000000
I20260812 06:20:06.356614 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushMRSOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.034s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1234474,"cfile_init":1,"dirs.queue_time_us":80,"dirs.run_cpu_time_us":281,"dirs.run_wall_time_us":1793,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2098,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:06.357605 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling LogGCOp(d97df3a0ac3946d084d6b12d3f52631a): free 124257186 bytes of WAL
I20260812 06:20:06.357868 10314 log_reader.cc:385] T d97df3a0ac3946d084d6b12d3f52631a: removed 12 log segments from log reader
I20260812 06:20:06.357918 10314 log.cc:1079] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/d97df3a0ac3946d084d6b12d3f52631a/wal-000000002 (ops 7-11)
I20260812 06:20:06.357983 10314 log.cc:1079] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/d97df3a0ac3946d084d6b12d3f52631a/wal-000000003 (ops 12-16)
I20260812 06:20:06.358034 10314 log.cc:1079] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/d97df3a0ac3946d084d6b12d3f52631a/wal-000000004 (ops 17-21)
I20260812 06:20:06.358055 10314 log.cc:1079] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/d97df3a0ac3946d084d6b12d3f52631a/wal-000000005 (ops 22-26)
I20260812 06:20:06.358112 10314 log.cc:1079] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/d97df3a0ac3946d084d6b12d3f52631a/wal-000000006 (ops 27-31)
I20260812 06:20:06.358155 10314 log.cc:1079] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/d97df3a0ac3946d084d6b12d3f52631a/wal-000000007 (ops 32-36)
I20260812 06:20:06.358192 10314 log.cc:1079] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/d97df3a0ac3946d084d6b12d3f52631a/wal-000000008 (ops 37-41)
I20260812 06:20:06.358253 10314 log.cc:1079] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/d97df3a0ac3946d084d6b12d3f52631a/wal-000000009 (ops 42-46)
I20260812 06:20:06.358290 10314 log.cc:1079] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/d97df3a0ac3946d084d6b12d3f52631a/wal-000000010 (ops 47-51)
I20260812 06:20:06.358331 10314 log.cc:1079] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/d97df3a0ac3946d084d6b12d3f52631a/wal-000000011 (ops 52-56)
I20260812 06:20:06.358369 10314 log.cc:1079] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/d97df3a0ac3946d084d6b12d3f52631a/wal-000000012 (ops 57-60)
I20260812 06:20:06.358404 10314 log.cc:1079] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/d97df3a0ac3946d084d6b12d3f52631a/wal-000000013 (ops 61-65)
I20260812 06:20:06.392683 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: LogGCOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.035s	user 0.001s	sys 0.032s Metrics: {}
I20260812 06:20:06.393257 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=3.181125
I20260812 06:20:06.407179 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.014s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4553929,"delete_count":0,"lbm_write_time_us":5540,"lbm_writes_lt_1ms":114,"reinsert_count":0,"update_count":555}
I20260812 06:20:06.407745 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=2.188937
I20260812 06:20:06.420310 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":3651380,"delete_count":0,"lbm_write_time_us":4444,"lbm_writes_lt_1ms":92,"reinsert_count":0,"update_count":445}
I20260812 06:20:06.421131 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling UndoDeltaBlockGCOp(d97df3a0ac3946d084d6b12d3f52631a): 473 bytes on disk
I20260812 06:20:06.422012 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: UndoDeltaBlockGCOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":131,"lbm_reads_lt_1ms":4}
I20260812 06:20:06.422681 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=1.000000
I20260812 06:20:06.630679 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.208s	user 0.158s	sys 0.039s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28795400,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":534,"lbm_read_time_us":16298,"lbm_reads_lt_1ms":674,"lbm_write_time_us":39775,"lbm_writes_lt_1ms":643,"mutex_wait_us":26,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":18944,"thread_start_us":105,"threads_started":1,"update_count":3000}
I20260812 06:20:06.631819 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=14.095187
I20260812 06:20:06.691560 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.059s	user 0.029s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25121,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:06.692159 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=2.188937
I20260812 06:20:06.706781 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.014s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5009,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:06.707758 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=1.000000
I20260812 06:20:06.891908 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.184s	user 0.124s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692758,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":403,"lbm_read_time_us":13066,"lbm_reads_lt_1ms":572,"lbm_write_time_us":36196,"lbm_writes_lt_1ms":543,"mutex_wait_us":108,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:20:06.892815 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=10.126437
I20260812 06:20:06.947933 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.055s	user 0.030s	sys 0.024s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":26580,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":300,"reinsert_count":0,"update_count":1500}
I20260812 06:20:06.948740 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=2.188937
I20260812 06:20:06.961365 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.012s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4701,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:06.962508 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=1.000000
I20260812 06:20:07.140806 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.178s	user 0.126s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590349,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":658,"lbm_read_time_us":15215,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28768,"lbm_writes_lt_1ms":443,"mutex_wait_us":99,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18944,"update_count":2000}
I20260812 06:20:07.141781 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=10.126437
I20260812 06:20:07.190904 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.049s	user 0.039s	sys 0.003s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":19989,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:07.191733 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=2.188937
I20260812 06:20:07.212083 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.020s	user 0.019s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7521,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.213089 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=1.000000
I20260812 06:20:07.386401 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.173s	user 0.119s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590348,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":438,"lbm_read_time_us":12360,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29607,"lbm_writes_lt_1ms":443,"mutex_wait_us":36,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15232,"update_count":2000}
I20260812 06:20:07.387203 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=10.126437
I20260812 06:20:07.444981 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.058s	user 0.015s	sys 0.028s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":21549,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:07.445724 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=2.188937
I20260812 06:20:07.460155 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4985,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.461093 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=1.000000
I20260812 06:20:07.631847 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.171s	user 0.126s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590348,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":836,"lbm_read_time_us":11652,"lbm_reads_lt_1ms":472,"lbm_write_time_us":34261,"lbm_writes_lt_1ms":443,"mutex_wait_us":68,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:20:07.632740 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=10.126437
I20260812 06:20:07.688503 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.056s	user 0.024s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":19016,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:07.689247 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=2.188937
I20260812 06:20:07.704854 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5641,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.705595 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=1.000000
I20260812 06:20:07.871043 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.165s	user 0.127s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590348,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1309,"lbm_read_time_us":13569,"lbm_reads_lt_1ms":472,"lbm_write_time_us":32855,"lbm_writes_lt_1ms":443,"mutex_wait_us":432,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15232,"update_count":2000}
I20260812 06:20:07.871783 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=10.126437
I20260812 06:20:07.926348 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.054s	user 0.020s	sys 0.031s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":20882,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:07.927827 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=1.000000
I20260812 06:20:07.939538 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.011s	user 0.002s	sys 0.004s Metrics: {"bytes_written":1312956,"delete_count":0,"lbm_write_time_us":1587,"lbm_writes_lt_1ms":35,"reinsert_count":0,"update_count":160}
I20260812 06:20:07.940193 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=1.196750
I20260812 06:20:07.954738 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":2789855,"delete_count":0,"lbm_write_time_us":5248,"lbm_writes_lt_1ms":71,"reinsert_count":0,"update_count":340}
I20260812 06:20:07.955543 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=1.000000
I20260812 06:20:08.140232 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.184s	user 0.137s	sys 0.043s Metrics: {"cfile_cache_miss":433,"cfile_cache_miss_bytes":20590374,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":120,"lbm_read_time_us":13211,"lbm_reads_lt_1ms":473,"lbm_write_time_us":35465,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":441,"mutex_wait_us":43,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":2000}
I20260812 06:20:08.141601 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=10.126437
I20260812 06:20:08.186731 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.045s	user 0.018s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17553,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":1500}
I20260812 06:20:08.187428 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=2.188937
I20260812 06:20:08.201417 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.014s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4979,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:08.202080 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushMRSOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=1.000000
I20260812 06:20:08.238332 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushMRSOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.036s	user 0.034s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":99,"dirs.run_cpu_time_us":313,"dirs.run_wall_time_us":1649,"drs_written":1,"lbm_read_time_us":113,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2414,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:08.239670 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling LogGCOp(d97df3a0ac3946d084d6b12d3f52631a): free 133024430 bytes of WAL
I20260812 06:20:08.240049 10314 log_reader.cc:385] T d97df3a0ac3946d084d6b12d3f52631a: removed 13 log segments from log reader
I20260812 06:20:08.240124 10314 log.cc:1079] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/d97df3a0ac3946d084d6b12d3f52631a/wal-000000014 (ops 66-70)
I20260812 06:20:08.240191 10314 log.cc:1079] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/d97df3a0ac3946d084d6b12d3f52631a/wal-000000015 (ops 71-75)
I20260812 06:20:08.240250 10314 log.cc:1079] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/d97df3a0ac3946d084d6b12d3f52631a/wal-000000016 (ops 76-80)
I20260812 06:20:08.240293 10314 log.cc:1079] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/d97df3a0ac3946d084d6b12d3f52631a/wal-000000017 (ops 81-85)
I20260812 06:20:08.240330 10314 log.cc:1079] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/d97df3a0ac3946d084d6b12d3f52631a/wal-000000018 (ops 86-90)
I20260812 06:20:08.240365 10314 log.cc:1079] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/d97df3a0ac3946d084d6b12d3f52631a/wal-000000019 (ops 91-95)
I20260812 06:20:08.240401 10314 log.cc:1079] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/d97df3a0ac3946d084d6b12d3f52631a/wal-000000020 (ops 96-100)
I20260812 06:20:08.240442 10314 log.cc:1079] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/d97df3a0ac3946d084d6b12d3f52631a/wal-000000021 (ops 101-105)
I20260812 06:20:08.240480 10314 log.cc:1079] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/d97df3a0ac3946d084d6b12d3f52631a/wal-000000022 (ops 106-110)
I20260812 06:20:08.240516 10314 log.cc:1079] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/d97df3a0ac3946d084d6b12d3f52631a/wal-000000023 (ops 111-115)
I20260812 06:20:08.240563 10314 log.cc:1079] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/d97df3a0ac3946d084d6b12d3f52631a/wal-000000024 (ops 116-120)
I20260812 06:20:08.240600 10314 log.cc:1079] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/d97df3a0ac3946d084d6b12d3f52631a/wal-000000025 (ops 121-124)
I20260812 06:20:08.240638 10314 log.cc:1079] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/d97df3a0ac3946d084d6b12d3f52631a/wal-000000026 (ops 125-129)
I20260812 06:20:08.278633 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: LogGCOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.039s	user 0.000s	sys 0.035s Metrics: {}
I20260812 06:20:08.279485 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling UndoDeltaBlockGCOp(d97df3a0ac3946d084d6b12d3f52631a): 483 bytes on disk
I20260812 06:20:08.280191 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: UndoDeltaBlockGCOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":96,"lbm_reads_lt_1ms":4}
I20260812 06:20:08.281077 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=3.181125
I20260812 06:20:08.320118 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.039s	user 0.013s	sys 0.023s Metrics: {"bytes_written":5251342,"delete_count":0,"lbm_write_time_us":9455,"lbm_writes_lt_1ms":131,"mutex_wait_us":39,"reinsert_count":0,"update_count":640}
I20260812 06:20:08.321346 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=1.196750
I20260812 06:20:08.337356 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":2953955,"delete_count":0,"lbm_write_time_us":5441,"lbm_writes_lt_1ms":75,"reinsert_count":0,"update_count":360}
I20260812 06:20:08.338161 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=1.000000
I20260812 06:20:08.571225 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.233s	user 0.156s	sys 0.072s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28795382,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1250,"lbm_read_time_us":17932,"lbm_reads_lt_1ms":674,"lbm_write_time_us":40383,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8448,"thread_start_us":454,"threads_started":1,"update_count":3000}
I20260812 06:20:08.572324 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=11.118625
I20260812 06:20:08.629596 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.057s	user 0.031s	sys 0.019s Metrics: {"bytes_written":13004907,"delete_count":0,"lbm_write_time_us":23357,"lbm_writes_lt_1ms":320,"reinsert_count":0,"update_count":1585}
I20260812 06:20:08.630249 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=2.188937
I20260812 06:20:08.652339 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.022s	user 0.006s	sys 0.007s Metrics: {"bytes_written":3815484,"delete_count":0,"lbm_write_time_us":4573,"lbm_writes_lt_1ms":96,"reinsert_count":0,"update_count":465}
I20260812 06:20:08.653044 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=2.188937
I20260812 06:20:08.671970 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.019s	user 0.014s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6895,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:08.672904 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=1.000000
I20260812 06:20:08.886601 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.213s	user 0.121s	sys 0.092s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24692866,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":253,"lbm_read_time_us":17208,"lbm_reads_lt_1ms":573,"lbm_write_time_us":38326,"lbm_writes_lt_1ms":543,"mutex_wait_us":59,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:08.887518 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=10.126437
I20260812 06:20:08.928709 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.041s	user 0.019s	sys 0.020s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18552,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:08.929455 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=2.188937
I20260812 06:20:08.949224 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.020s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":7721,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:08.949870 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=1.000000
I20260812 06:20:09.131543 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.181s	user 0.137s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":987,"lbm_read_time_us":11166,"lbm_reads_lt_1ms":468,"lbm_write_time_us":32122,"lbm_writes_lt_1ms":443,"mutex_wait_us":416,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2000}
I20260812 06:20:09.132397 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=11.118625
I20260812 06:20:09.174731 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.042s	user 0.030s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":18078,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:09.175387 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=2.188937
I20260812 06:20:09.206115 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.031s	user 0.006s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6760,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:09.206763 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=2.188937
I20260812 06:20:09.220139 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.013s	user 0.003s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5088,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:09.220876 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=1.000000
I20260812 06:20:09.400292 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.179s	user 0.126s	sys 0.052s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24692869,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":2026,"lbm_read_time_us":14646,"lbm_reads_lt_1ms":573,"lbm_write_time_us":37350,"lbm_writes_lt_1ms":543,"mutex_wait_us":478,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:20:09.401266 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=11.118625
I20260812 06:20:09.439368 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.038s	user 0.026s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16798,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:09.440312 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=2.188937
I20260812 06:20:09.465392 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.025s	user 0.003s	sys 0.012s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6808,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:09.466040 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=1.000000
I20260812 06:20:09.616284 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.150s	user 0.120s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590338,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1202,"lbm_read_time_us":9825,"lbm_reads_lt_1ms":464,"lbm_write_time_us":31728,"lbm_writes_lt_1ms":443,"mutex_wait_us":411,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":19712,"update_count":2000}
I20260812 06:20:09.617280 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=11.118625
I20260812 06:20:09.670871 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.053s	user 0.027s	sys 0.022s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":19873,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:09.671747 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=2.188937
I20260812 06:20:09.683708 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4516,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:09.684321 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=1.000000
I20260812 06:20:09.850878 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.166s	user 0.098s	sys 0.068s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590338,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":302,"lbm_read_time_us":13709,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29161,"lbm_writes_lt_1ms":443,"mutex_wait_us":44,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:09.851671 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=10.126437
I20260812 06:20:09.888566 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.036s	user 0.020s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16494,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:09.889424 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=1.000000
I20260812 06:20:10.019356 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.130s	user 0.097s	sys 0.032s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16487816,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1252,"lbm_read_time_us":9899,"lbm_reads_lt_1ms":367,"lbm_write_time_us":24367,"lbm_writes_lt_1ms":343,"mutex_wait_us":476,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":15360,"update_count":1500}
I20260812 06:20:10.020211 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=10.126437
I20260812 06:20:10.080119 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.060s	user 0.040s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":24054,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:10.080926 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=2.188937
I20260812 06:20:10.095041 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.014s	user 0.003s	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:20:10.096024 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushMRSOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=1.000000
I20260812 06:20:10.133129 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushMRSOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.037s	user 0.027s	sys 0.007s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":296,"dirs.run_wall_time_us":1468,"drs_written":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2732,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:10.134012 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling LogGCOp(d97df3a0ac3946d084d6b12d3f52631a): free 124710526 bytes of WAL
I20260812 06:20:10.134276 10314 log_reader.cc:385] T d97df3a0ac3946d084d6b12d3f52631a: removed 12 log segments from log reader
I20260812 06:20:10.134325 10314 log.cc:1079] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/d97df3a0ac3946d084d6b12d3f52631a/wal-000000027 (ops 130-134)
I20260812 06:20:10.134382 10314 log.cc:1079] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/d97df3a0ac3946d084d6b12d3f52631a/wal-000000028 (ops 135-139)
I20260812 06:20:10.134426 10314 log.cc:1079] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/d97df3a0ac3946d084d6b12d3f52631a/wal-000000029 (ops 140-144)
I20260812 06:20:10.134490 10314 log.cc:1079] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/d97df3a0ac3946d084d6b12d3f52631a/wal-000000030 (ops 145-149)
I20260812 06:20:10.134537 10314 log.cc:1079] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/d97df3a0ac3946d084d6b12d3f52631a/wal-000000031 (ops 150-154)
I20260812 06:20:10.134577 10314 log.cc:1079] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/d97df3a0ac3946d084d6b12d3f52631a/wal-000000032 (ops 155-159)
I20260812 06:20:10.134619 10314 log.cc:1079] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/d97df3a0ac3946d084d6b12d3f52631a/wal-000000033 (ops 160-164)
I20260812 06:20:10.134662 10314 log.cc:1079] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/d97df3a0ac3946d084d6b12d3f52631a/wal-000000034 (ops 165-169)
I20260812 06:20:10.134706 10314 log.cc:1079] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/d97df3a0ac3946d084d6b12d3f52631a/wal-000000035 (ops 170-174)
I20260812 06:20:10.134747 10314 log.cc:1079] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/d97df3a0ac3946d084d6b12d3f52631a/wal-000000036 (ops 175-179)
I20260812 06:20:10.134786 10314 log.cc:1079] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/d97df3a0ac3946d084d6b12d3f52631a/wal-000000037 (ops 180-184)
I20260812 06:20:10.134895 10314 log.cc:1079] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/d97df3a0ac3946d084d6b12d3f52631a/wal-000000038 (ops 185-189)
I20260812 06:20:10.167447 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: LogGCOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.033s	user 0.000s	sys 0.033s Metrics: {}
I20260812 06:20:10.168015 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling UndoDeltaBlockGCOp(d97df3a0ac3946d084d6b12d3f52631a): 482 bytes on disk
I20260812 06:20:10.168788 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: UndoDeltaBlockGCOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4}
I20260812 06:20:10.169607 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=3.181125
I20260812 06:20:10.189682 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.020s	user 0.008s	sys 0.009s Metrics: {"bytes_written":5210311,"delete_count":0,"lbm_write_time_us":8205,"lbm_writes_lt_1ms":130,"reinsert_count":0,"update_count":635}
I20260812 06:20:10.190665 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=1.196750
I20260812 06:20:10.204419 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.013s	user 0.004s	sys 0.007s Metrics: {"bytes_written":2994980,"delete_count":0,"lbm_write_time_us":5207,"lbm_writes_lt_1ms":76,"reinsert_count":0,"update_count":365}
I20260812 06:20:10.205157 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=1.000000
I20260812 06:20:10.438162 10160 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.937s	user 2.199s	sys 0.118s
I20260812 06:20:10.441365 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: MajorDeltaCompactionOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.236s	user 0.165s	sys 0.064s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28795383,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":207,"lbm_read_time_us":16972,"lbm_reads_lt_1ms":674,"lbm_write_time_us":47691,"lbm_writes_lt_1ms":643,"mutex_wait_us":2,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2688,"thread_start_us":129,"threads_started":1,"update_count":3000}
I20260812 06:20:10.442096 10410 maintenance_manager.cc:419] P 055d9136d44b4b31a2525e0607c56a0e: Scheduling FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a): perf score=14.095187
I20260812 06:20:10.483959 10160 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.045s	user 0.004s	sys 0.000s
I20260812 06:20:10.484895 10160 tablet_server.cc:179] TabletServer@127.9.236.1:0 shutting down...
I20260812 06:20:10.510562 10314 maintenance_manager.cc:643] P 055d9136d44b4b31a2525e0607c56a0e: FlushDeltaMemStoresOp(d97df3a0ac3946d084d6b12d3f52631a) complete. Timing: real 0.068s	user 0.023s	sys 0.041s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":34083,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:10.511536 10160 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:10.512019 10160 tablet_replica.cc:333] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e: stopping tablet replica
I20260812 06:20:10.512346 10160 raft_consensus.cc:2243] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:10.512660 10160 raft_consensus.cc:2272] T d97df3a0ac3946d084d6b12d3f52631a P 055d9136d44b4b31a2525e0607c56a0e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:10.528993 10160 tablet_server.cc:196] TabletServer@127.9.236.1:0 shutdown complete.
I20260812 06:20:10.535483 10160 master.cc:562] Master@127.9.236.62:38917 shutting down...
I20260812 06:20:10.539515 10160 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 92e0b45bab2b40cb82c33ecd93baf246 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:10.539741 10160 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 92e0b45bab2b40cb82c33ecd93baf246 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:10.539803 10160 tablet_replica.cc:333] T 00000000000000000000000000000000 P 92e0b45bab2b40cb82c33ecd93baf246: stopping tablet replica
I20260812 06:20:10.552762 10160 master.cc:584] Master@127.9.236.62:38917 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (6505 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:10.660117 10160 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.9.236.62:44379
I20260812 06:20:10.660585 10160 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:10.663416 10467 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:20:10.663581 10160 server_base.cc:1061] running on GCE node
W20260812 06:20:10.663681 10465 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:20:10.663583 10463 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:20:10.664115 10160 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:10.664161 10160 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:20:10.664201 10160 hybrid_clock.cc:648] HybridClock initialized: now 1786515610664200 us; error 0 us; skew 500 ppm
I20260812 06:20:10.665227 10160 webserver.cc:533] Webserver started at http://127.9.236.62:39219/ using document root <none> and password file <none>
I20260812 06:20:10.665431 10160 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:10.665495 10160 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:10.665606 10160 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:10.666085 10160 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/master-0-root/instance:
uuid: "59333c3ead3241559dee95e1e958dfa2"
format_stamp: "Formatted at 2026-08-12 06:20:10 on dist-test-slave-h3ft"
I20260812 06:20:10.668046 10160 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:10.669360 10479 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:20:10.669724 10160 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:10.669803 10160 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/master-0-root
uuid: "59333c3ead3241559dee95e1e958dfa2"
format_stamp: "Formatted at 2026-08-12 06:20:10 on dist-test-slave-h3ft"
I20260812 06:20:10.669886 10160 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-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:20:10.693919 10160 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:10.694587 10160 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:10.700284 10160 rpc_server.cc:307] RPC server started. Bound to: 127.9.236.62:44379
I20260812 06:20:10.703205 10560 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.9.236.62:44379 every 8 connection(s)
I20260812 06:20:10.721117 10561 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:20:10.724905 10561 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 59333c3ead3241559dee95e1e958dfa2: Bootstrap starting.
I20260812 06:20:10.725975 10561 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 59333c3ead3241559dee95e1e958dfa2: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:10.727533 10561 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 59333c3ead3241559dee95e1e958dfa2: No bootstrap required, opened a new log
I20260812 06:20:10.728065 10561 raft_consensus.cc:359] T 00000000000000000000000000000000 P 59333c3ead3241559dee95e1e958dfa2 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "59333c3ead3241559dee95e1e958dfa2" member_type: VOTER }
I20260812 06:20:10.728176 10561 raft_consensus.cc:385] T 00000000000000000000000000000000 P 59333c3ead3241559dee95e1e958dfa2 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:10.728201 10561 raft_consensus.cc:740] T 00000000000000000000000000000000 P 59333c3ead3241559dee95e1e958dfa2 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 59333c3ead3241559dee95e1e958dfa2, State: Initialized, Role: FOLLOWER
I20260812 06:20:10.728340 10561 consensus_queue.cc:260] T 00000000000000000000000000000000 P 59333c3ead3241559dee95e1e958dfa2 [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: "59333c3ead3241559dee95e1e958dfa2" member_type: VOTER }
I20260812 06:20:10.728412 10561 raft_consensus.cc:399] T 00000000000000000000000000000000 P 59333c3ead3241559dee95e1e958dfa2 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:10.728461 10561 raft_consensus.cc:493] T 00000000000000000000000000000000 P 59333c3ead3241559dee95e1e958dfa2 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:10.728502 10561 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 59333c3ead3241559dee95e1e958dfa2 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:10.729341 10561 raft_consensus.cc:515] T 00000000000000000000000000000000 P 59333c3ead3241559dee95e1e958dfa2 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "59333c3ead3241559dee95e1e958dfa2" member_type: VOTER }
I20260812 06:20:10.729497 10561 leader_election.cc:304] T 00000000000000000000000000000000 P 59333c3ead3241559dee95e1e958dfa2 [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: 59333c3ead3241559dee95e1e958dfa2; no voters: 
I20260812 06:20:10.729729 10561 leader_election.cc:290] T 00000000000000000000000000000000 P 59333c3ead3241559dee95e1e958dfa2 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:10.730073 10565 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 59333c3ead3241559dee95e1e958dfa2 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:10.730330 10561 sys_catalog.cc:565] T 00000000000000000000000000000000 P 59333c3ead3241559dee95e1e958dfa2 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:10.730361 10565 raft_consensus.cc:697] T 00000000000000000000000000000000 P 59333c3ead3241559dee95e1e958dfa2 [term 1 LEADER]: Becoming Leader. State: Replica: 59333c3ead3241559dee95e1e958dfa2, State: Running, Role: LEADER
I20260812 06:20:10.730540 10565 consensus_queue.cc:237] T 00000000000000000000000000000000 P 59333c3ead3241559dee95e1e958dfa2 [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: "59333c3ead3241559dee95e1e958dfa2" member_type: VOTER }
I20260812 06:20:10.731262 10567 sys_catalog.cc:455] T 00000000000000000000000000000000 P 59333c3ead3241559dee95e1e958dfa2 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 59333c3ead3241559dee95e1e958dfa2. Latest consensus state: current_term: 1 leader_uuid: "59333c3ead3241559dee95e1e958dfa2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "59333c3ead3241559dee95e1e958dfa2" member_type: VOTER } }
I20260812 06:20:10.731398 10567 sys_catalog.cc:458] T 00000000000000000000000000000000 P 59333c3ead3241559dee95e1e958dfa2 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:10.731567 10566 sys_catalog.cc:455] T 00000000000000000000000000000000 P 59333c3ead3241559dee95e1e958dfa2 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "59333c3ead3241559dee95e1e958dfa2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "59333c3ead3241559dee95e1e958dfa2" member_type: VOTER } }
I20260812 06:20:10.731745 10566 sys_catalog.cc:458] T 00000000000000000000000000000000 P 59333c3ead3241559dee95e1e958dfa2 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:10.732239 10577 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:10.733206 10577 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:10.733429 10160 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:10.735486 10577 catalog_manager.cc:1383] Generated new cluster ID: 00bc3c6fdd8f46209812081a66aecf02
I20260812 06:20:10.735553 10577 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:10.753146 10577 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:10.753957 10577 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:10.760819 10577 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 59333c3ead3241559dee95e1e958dfa2: Generated new TSK 0
I20260812 06:20:10.761085 10577 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:10.766108 10160 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:10.768628 10595 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:20:10.768628 10593 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:20:10.768653 10592 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:20:10.768824 10160 server_base.cc:1061] running on GCE node
I20260812 06:20:10.769134 10160 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:10.769186 10160 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:20:10.769203 10160 hybrid_clock.cc:648] HybridClock initialized: now 1786515610769203 us; error 0 us; skew 500 ppm
I20260812 06:20:10.770143 10160 webserver.cc:533] Webserver started at http://127.9.236.1:37837/ using document root <none> and password file <none>
I20260812 06:20:10.770318 10160 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:10.770370 10160 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:10.770433 10160 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:10.771077 10160 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root/instance:
uuid: "08e309e4e721480085074f9da5fcd5a5"
format_stamp: "Formatted at 2026-08-12 06:20:10 on dist-test-slave-h3ft"
I20260812 06:20:10.772746 10160 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:10.773871 10603 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:20:10.774160 10160 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:10.774257 10160 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root
uuid: "08e309e4e721480085074f9da5fcd5a5"
format_stamp: "Formatted at 2026-08-12 06:20:10 on dist-test-slave-h3ft"
I20260812 06:20:10.774353 10160 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-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:20:10.791992 10160 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:10.792591 10160 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:10.793008 10160 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:10.793591 10160 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:10.793659 10160 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:10.793730 10160 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:10.793766 10160 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:10.799135 10160 rpc_server.cc:307] RPC server started. Bound to: 127.9.236.1:35421
I20260812 06:20:10.799198 10699 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.9.236.1:35421 every 8 connection(s)
I20260812 06:20:10.810243 10700 heartbeater.cc:344] Connected to a master server at 127.9.236.62:44379
I20260812 06:20:10.810467 10700 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:10.810839 10700 heartbeater.cc:507] Master 127.9.236.62:44379 requested a full tablet report, sending...
I20260812 06:20:10.811748 10506 ts_manager.cc:194] Registered new tserver with Master: 08e309e4e721480085074f9da5fcd5a5 (127.9.236.1:35421)
I20260812 06:20:10.811972 10160 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012302783s
I20260812 06:20:10.812685 10506 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:40256
I20260812 06:20:10.820794 10506 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:40264:
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:20:10.831916 10640 tablet_service.cc:1511] Processing CreateTablet for tablet 8f4fb40221f74532a2a8dd9307ec7e74 (DEFAULT_TABLE table=heavy-update-compaction-test [id=71f80df5b2724c028d77e19b6586b882]), partition=
I20260812 06:20:10.832353 10640 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 8f4fb40221f74532a2a8dd9307ec7e74. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:10.834971 10715 tablet_bootstrap.cc:492] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Bootstrap starting.
I20260812 06:20:10.836277 10715 tablet_bootstrap.cc:654] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:10.837858 10715 tablet_bootstrap.cc:492] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: No bootstrap required, opened a new log
I20260812 06:20:10.838140 10715 ts_tablet_manager.cc:1403] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:20:10.838696 10715 raft_consensus.cc:359] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "08e309e4e721480085074f9da5fcd5a5" member_type: VOTER last_known_addr { host: "127.9.236.1" port: 35421 } }
I20260812 06:20:10.838810 10715 raft_consensus.cc:385] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:10.838871 10715 raft_consensus.cc:740] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 08e309e4e721480085074f9da5fcd5a5, State: Initialized, Role: FOLLOWER
I20260812 06:20:10.839130 10715 consensus_queue.cc:260] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5 [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: "08e309e4e721480085074f9da5fcd5a5" member_type: VOTER last_known_addr { host: "127.9.236.1" port: 35421 } }
I20260812 06:20:10.839231 10715 raft_consensus.cc:399] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:10.839303 10715 raft_consensus.cc:493] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:10.839372 10715 raft_consensus.cc:3060] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:10.840533 10715 raft_consensus.cc:515] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "08e309e4e721480085074f9da5fcd5a5" member_type: VOTER last_known_addr { host: "127.9.236.1" port: 35421 } }
I20260812 06:20:10.840721 10715 leader_election.cc:304] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5 [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: 08e309e4e721480085074f9da5fcd5a5; no voters: 
I20260812 06:20:10.841063 10715 leader_election.cc:290] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:10.841166 10717 raft_consensus.cc:2804] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:10.841451 10717 raft_consensus.cc:697] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5 [term 1 LEADER]: Becoming Leader. State: Replica: 08e309e4e721480085074f9da5fcd5a5, State: Running, Role: LEADER
I20260812 06:20:10.841547 10715 ts_tablet_manager.cc:1434] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Time spent starting tablet: real 0.003s	user 0.001s	sys 0.003s
I20260812 06:20:10.841564 10700 heartbeater.cc:499] Master 127.9.236.62:44379 was elected leader, sending a full tablet report...
I20260812 06:20:10.841694 10717 consensus_queue.cc:237] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5 [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: "08e309e4e721480085074f9da5fcd5a5" member_type: VOTER last_known_addr { host: "127.9.236.1" port: 35421 } }
I20260812 06:20:10.843479 10506 catalog_manager.cc:5719] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5 reported cstate change: term changed from 0 to 1, leader changed from <none> to 08e309e4e721480085074f9da5fcd5a5 (127.9.236.1). New cstate: current_term: 1 leader_uuid: "08e309e4e721480085074f9da5fcd5a5" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "08e309e4e721480085074f9da5fcd5a5" member_type: VOTER last_known_addr { host: "127.9.236.1" port: 35421 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:10.916116 10160 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.068s	user 0.016s	sys 0.012s
I20260812 06:20:11.050279 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushMRSOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=15.086190
I20260812 06:20:11.186620 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushMRSOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.136s	user 0.117s	sys 0.016s Metrics: {"bytes_written":8205078,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":110,"dirs.run_cpu_time_us":253,"dirs.run_wall_time_us":836,"drs_written":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36849,"lbm_writes_lt_1ms":557,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"update_count":1000}
I20260812 06:20:11.187430 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling UndoDeltaBlockGCOp(8f4fb40221f74532a2a8dd9307ec7e74): 12308960 bytes on disk
I20260812 06:20:11.188186 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: UndoDeltaBlockGCOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":91,"lbm_reads_lt_1ms":4}
I20260812 06:20:11.188663 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=1.000000
I20260812 06:20:11.297894 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.109s	user 0.063s	sys 0.044s Metrics: {"cfile_cache_miss":231,"cfile_cache_miss_bytes":12426369,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":797,"lbm_read_time_us":8948,"lbm_reads_lt_1ms":259,"lbm_write_time_us":18380,"lbm_writes_lt_1ms":243,"peak_mem_usage":25836184,"reinsert_count":0,"thread_start_us":391,"threads_started":5,"update_count":1000}
I20260812 06:20:11.298594 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling LogGCOp(8f4fb40221f74532a2a8dd9307ec7e74): free 11976772 bytes of WAL
I20260812 06:20:11.298893 10608 log_reader.cc:385] T 8f4fb40221f74532a2a8dd9307ec7e74: removed 1 log segments from log reader
I20260812 06:20:11.298974 10608 log.cc:1079] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/8f4fb40221f74532a2a8dd9307ec7e74/wal-000000001 (ops 1-6)
I20260812 06:20:11.302809 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: LogGCOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.004s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:20:11.303416 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=7.149875
I20260812 06:20:11.333413 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.030s	user 0.008s	sys 0.020s Metrics: {"bytes_written":9353756,"delete_count":0,"lbm_write_time_us":12897,"lbm_writes_lt_1ms":231,"mutex_wait_us":73,"reinsert_count":0,"update_count":1140}
I20260812 06:20:11.334398 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=1.196750
I20260812 06:20:11.348878 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.014s	user 0.010s	sys 0.000s Metrics: {"bytes_written":2953955,"delete_count":0,"lbm_write_time_us":3782,"lbm_writes_lt_1ms":75,"reinsert_count":0,"update_count":360}
I20260812 06:20:11.349586 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=1.000000
I20260812 06:20:11.476794 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.127s	user 0.100s	sys 0.019s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528874,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":521,"lbm_read_time_us":7566,"lbm_reads_lt_1ms":368,"lbm_write_time_us":22113,"lbm_writes_lt_1ms":343,"mutex_wait_us":104,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":16640,"update_count":1500}
I20260812 06:20:11.477466 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=10.126437
I20260812 06:20:11.522846 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.045s	user 0.021s	sys 0.014s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16186,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:11.523587 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=1.000000
I20260812 06:20:11.640519 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.117s	user 0.092s	sys 0.025s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528782,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":652,"lbm_read_time_us":8817,"lbm_reads_lt_1ms":363,"lbm_write_time_us":21906,"lbm_writes_lt_1ms":343,"mutex_wait_us":127,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":1500}
I20260812 06:20:11.641288 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=10.126437
I20260812 06:20:11.694959 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.053s	user 0.027s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18714,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:11.695593 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=2.188937
I20260812 06:20:11.707830 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4604,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:11.708618 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=1.000000
I20260812 06:20:11.859874 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.151s	user 0.107s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":360,"lbm_read_time_us":10980,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27928,"lbm_writes_lt_1ms":443,"mutex_wait_us":73,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16128,"update_count":2000}
I20260812 06:20:11.860603 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=10.126437
I20260812 06:20:11.903584 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.043s	user 0.024s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16700,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:11.904078 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=1.000000
I20260812 06:20:12.031157 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.127s	user 0.085s	sys 0.035s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528782,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":810,"lbm_read_time_us":7563,"lbm_reads_lt_1ms":363,"lbm_write_time_us":20957,"lbm_writes_lt_1ms":343,"mutex_wait_us":384,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":25344,"update_count":1500}
I20260812 06:20:12.031939 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=10.126437
I20260812 06:20:12.073077 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.041s	user 0.023s	sys 0.016s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":17492,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:12.074014 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=1.000000
I20260812 06:20:12.225690 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.151s	user 0.114s	sys 0.024s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528783,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":820,"lbm_read_time_us":9505,"lbm_reads_lt_1ms":363,"lbm_write_time_us":21812,"lbm_writes_lt_1ms":343,"mutex_wait_us":378,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":11520,"update_count":1500}
I20260812 06:20:12.226405 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=10.126437
I20260812 06:20:12.268204 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.042s	user 0.033s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19249,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:12.268786 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=1.000000
I20260812 06:20:12.390565 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.122s	user 0.104s	sys 0.017s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528781,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":824,"lbm_read_time_us":8210,"lbm_reads_lt_1ms":363,"lbm_write_time_us":24387,"lbm_writes_lt_1ms":343,"mutex_wait_us":409,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":12416,"update_count":1500}
I20260812 06:20:12.391284 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=10.126437
I20260812 06:20:12.439078 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.048s	user 0.026s	sys 0.019s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":20579,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:12.439982 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=1.000000
I20260812 06:20:12.591463 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.151s	user 0.110s	sys 0.033s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528784,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":705,"lbm_read_time_us":11290,"lbm_reads_lt_1ms":367,"lbm_write_time_us":27736,"lbm_writes_lt_1ms":343,"mutex_wait_us":370,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":14848,"update_count":1500}
I20260812 06:20:12.592340 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=10.126437
I20260812 06:20:12.646656 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.054s	user 0.014s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18665,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:12.647354 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=2.188937
I20260812 06:20:12.660363 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4683,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:12.661158 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushMRSOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=1.000000
I20260812 06:20:12.697999 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushMRSOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.037s	user 0.031s	sys 0.003s Metrics: {"bytes_written":1152509,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":360,"dirs.run_wall_time_us":1672,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2169,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:12.698800 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling LogGCOp(8f4fb40221f74532a2a8dd9307ec7e74): free 112692317 bytes of WAL
I20260812 06:20:12.699117 10608 log_reader.cc:385] T 8f4fb40221f74532a2a8dd9307ec7e74: removed 11 log segments from log reader
I20260812 06:20:12.699200 10608 log.cc:1079] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/8f4fb40221f74532a2a8dd9307ec7e74/wal-000000002 (ops 7-11)
I20260812 06:20:12.699277 10608 log.cc:1079] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/8f4fb40221f74532a2a8dd9307ec7e74/wal-000000003 (ops 12-16)
I20260812 06:20:12.699342 10608 log.cc:1079] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/8f4fb40221f74532a2a8dd9307ec7e74/wal-000000004 (ops 17-21)
I20260812 06:20:12.699400 10608 log.cc:1079] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/8f4fb40221f74532a2a8dd9307ec7e74/wal-000000005 (ops 22-26)
I20260812 06:20:12.699440 10608 log.cc:1079] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/8f4fb40221f74532a2a8dd9307ec7e74/wal-000000006 (ops 27-31)
I20260812 06:20:12.699481 10608 log.cc:1079] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/8f4fb40221f74532a2a8dd9307ec7e74/wal-000000007 (ops 32-36)
I20260812 06:20:12.699527 10608 log.cc:1079] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/8f4fb40221f74532a2a8dd9307ec7e74/wal-000000008 (ops 37-41)
I20260812 06:20:12.699570 10608 log.cc:1079] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/8f4fb40221f74532a2a8dd9307ec7e74/wal-000000009 (ops 42-46)
I20260812 06:20:12.699613 10608 log.cc:1079] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/8f4fb40221f74532a2a8dd9307ec7e74/wal-000000010 (ops 47-51)
I20260812 06:20:12.699658 10608 log.cc:1079] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/8f4fb40221f74532a2a8dd9307ec7e74/wal-000000011 (ops 52-56)
I20260812 06:20:12.699702 10608 log.cc:1079] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/8f4fb40221f74532a2a8dd9307ec7e74/wal-000000012 (ops 57-61)
I20260812 06:20:12.734630 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: LogGCOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.036s	user 0.000s	sys 0.032s Metrics: {}
I20260812 06:20:12.735383 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=3.181125
I20260812 06:20:12.756517 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.021s	user 0.016s	sys 0.001s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7212,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:12.757195 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling UndoDeltaBlockGCOp(8f4fb40221f74532a2a8dd9307ec7e74): 447 bytes on disk
I20260812 06:20:12.757716 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: UndoDeltaBlockGCOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4}
I20260812 06:20:12.758194 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=2.188937
I20260812 06:20:12.770051 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4623,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:12.770768 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=1.000000
I20260812 06:20:13.013686 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.243s	user 0.153s	sys 0.090s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836360,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":680,"lbm_read_time_us":18368,"lbm_reads_lt_1ms":674,"lbm_write_time_us":42720,"lbm_writes_lt_1ms":643,"mutex_wait_us":60,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":17664,"thread_start_us":146,"threads_started":1,"update_count":3000}
I20260812 06:20:13.014554 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=14.095187
I20260812 06:20:13.091456 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.077s	user 0.038s	sys 0.039s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":27604,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:13.092319 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=2.188937
I20260812 06:20:13.111265 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.019s	user 0.018s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7605,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:13.111846 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=1.000000
I20260812 06:20:13.322341 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.210s	user 0.125s	sys 0.085s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":467,"lbm_read_time_us":16823,"lbm_reads_lt_1ms":572,"lbm_write_time_us":36529,"lbm_writes_lt_1ms":543,"mutex_wait_us":68,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12032,"update_count":2500}
I20260812 06:20:13.323204 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=10.126437
I20260812 06:20:13.376654 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.053s	user 0.015s	sys 0.036s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":26655,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:20:13.378036 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=2.188937
I20260812 06:20:13.396059 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.018s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6654,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:13.396730 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=1.000000
I20260812 06:20:13.597165 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.200s	user 0.113s	sys 0.069s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":343,"lbm_read_time_us":13642,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26550,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":2000}
I20260812 06:20:13.597952 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=12.110812
I20260812 06:20:13.647135 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.049s	user 0.021s	sys 0.026s Metrics: {"bytes_written":13497196,"delete_count":0,"lbm_write_time_us":21590,"lbm_writes_lt_1ms":332,"reinsert_count":0,"update_count":1645}
I20260812 06:20:13.647688 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=2.188937
I20260812 06:20:13.670195 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.022s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3323184,"delete_count":0,"lbm_write_time_us":5544,"lbm_writes_lt_1ms":84,"reinsert_count":0,"update_count":405}
I20260812 06:20:13.670740 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=2.188937
I20260812 06:20:13.681408 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3942,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:13.681870 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=1.000000
I20260812 06:20:13.852486 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.170s	user 0.122s	sys 0.048s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733820,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":776,"lbm_read_time_us":13197,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32286,"lbm_writes_lt_1ms":543,"mutex_wait_us":449,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:13.853364 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=10.126437
I20260812 06:20:13.897087 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.043s	user 0.019s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16516,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:13.897954 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=2.188937
I20260812 06:20:13.910588 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.012s	user 0.000s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5074,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:13.911440 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=1.000000
I20260812 06:20:14.065663 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.154s	user 0.101s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1284,"lbm_read_time_us":13106,"lbm_reads_lt_1ms":472,"lbm_write_time_us":30765,"lbm_writes_lt_1ms":443,"mutex_wait_us":526,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5632,"update_count":2000}
I20260812 06:20:14.066495 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=10.126437
I20260812 06:20:14.131404 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.065s	user 0.021s	sys 0.039s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":23303,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:20:14.132134 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=2.188937
I20260812 06:20:14.143934 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.012s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4710,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.144445 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=1.000000
I20260812 06:20:14.310065 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.165s	user 0.101s	sys 0.064s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":637,"lbm_read_time_us":13085,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28771,"lbm_writes_lt_1ms":443,"mutex_wait_us":365,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18688,"update_count":2000}
I20260812 06:20:14.310858 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=10.126437
I20260812 06:20:14.368150 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.057s	user 0.029s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20034,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:14.368814 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=2.188937
I20260812 06:20:14.383256 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.014s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5279,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.383975 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushMRSOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=1.000000
I20260812 06:20:14.417825 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushMRSOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.034s	user 0.027s	sys 0.004s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":105,"dirs.run_cpu_time_us":262,"dirs.run_wall_time_us":1416,"drs_written":1,"lbm_read_time_us":95,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2251,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:14.418702 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling LogGCOp(8f4fb40221f74532a2a8dd9307ec7e74): free 116849580 bytes of WAL
I20260812 06:20:14.419029 10608 log_reader.cc:385] T 8f4fb40221f74532a2a8dd9307ec7e74: removed 12 log segments from log reader
I20260812 06:20:14.419103 10608 log.cc:1079] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/8f4fb40221f74532a2a8dd9307ec7e74/wal-000000013 (ops 62-66)
I20260812 06:20:14.419152 10608 log.cc:1079] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/8f4fb40221f74532a2a8dd9307ec7e74/wal-000000014 (ops 67-70)
I20260812 06:20:14.419183 10608 log.cc:1079] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/8f4fb40221f74532a2a8dd9307ec7e74/wal-000000015 (ops 71-75)
I20260812 06:20:14.419216 10608 log.cc:1079] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/8f4fb40221f74532a2a8dd9307ec7e74/wal-000000016 (ops 76-80)
I20260812 06:20:14.419245 10608 log.cc:1079] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/8f4fb40221f74532a2a8dd9307ec7e74/wal-000000017 (ops 81-84)
I20260812 06:20:14.419270 10608 log.cc:1079] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/8f4fb40221f74532a2a8dd9307ec7e74/wal-000000018 (ops 85-89)
I20260812 06:20:14.419301 10608 log.cc:1079] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/8f4fb40221f74532a2a8dd9307ec7e74/wal-000000019 (ops 90-94)
I20260812 06:20:14.419329 10608 log.cc:1079] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/8f4fb40221f74532a2a8dd9307ec7e74/wal-000000020 (ops 95-99)
I20260812 06:20:14.419360 10608 log.cc:1079] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/8f4fb40221f74532a2a8dd9307ec7e74/wal-000000021 (ops 100-104)
I20260812 06:20:14.419394 10608 log.cc:1079] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/8f4fb40221f74532a2a8dd9307ec7e74/wal-000000022 (ops 105-108)
I20260812 06:20:14.419430 10608 log.cc:1079] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/8f4fb40221f74532a2a8dd9307ec7e74/wal-000000023 (ops 109-113)
I20260812 06:20:14.419461 10608 log.cc:1079] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/8f4fb40221f74532a2a8dd9307ec7e74/wal-000000024 (ops 114-118)
I20260812 06:20:14.457599 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: LogGCOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.039s	user 0.002s	sys 0.035s Metrics: {}
I20260812 06:20:14.458185 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling UndoDeltaBlockGCOp(8f4fb40221f74532a2a8dd9307ec7e74): 448 bytes on disk
I20260812 06:20:14.458774 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: UndoDeltaBlockGCOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":79,"lbm_reads_lt_1ms":4}
I20260812 06:20:14.459582 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=3.181125
I20260812 06:20:14.494074 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.034s	user 0.007s	sys 0.017s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7063,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:14.494735 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling LogGCOp(8f4fb40221f74532a2a8dd9307ec7e74): free 11564875 bytes of WAL
I20260812 06:20:14.494967 10608 log_reader.cc:385] T 8f4fb40221f74532a2a8dd9307ec7e74: removed 1 log segments from log reader
I20260812 06:20:14.495066 10608 log.cc:1079] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/8f4fb40221f74532a2a8dd9307ec7e74/wal-000000025 (ops 119-122)
I20260812 06:20:14.497776 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: LogGCOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:20:14.498174 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=2.188937
I20260812 06:20:14.509850 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4436,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:14.510479 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=1.000000
I20260812 06:20:14.759506 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.249s	user 0.162s	sys 0.073s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836361,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1374,"lbm_read_time_us":19631,"lbm_reads_lt_1ms":674,"lbm_write_time_us":42902,"lbm_writes_lt_1ms":643,"mutex_wait_us":446,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16384,"thread_start_us":151,"threads_started":1,"update_count":3000}
I20260812 06:20:14.761097 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=14.095187
I20260812 06:20:14.839500 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.078s	user 0.018s	sys 0.059s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":30937,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:14.840250 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=2.188937
I20260812 06:20:14.857312 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.017s	user 0.014s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6836,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.857944 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=1.000000
I20260812 06:20:15.070974 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.213s	user 0.127s	sys 0.072s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":722,"lbm_read_time_us":16847,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34302,"lbm_writes_lt_1ms":543,"mutex_wait_us":358,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":2500}
I20260812 06:20:15.071851 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=14.095187
I20260812 06:20:15.141229 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.069s	user 0.048s	sys 0.018s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":31826,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:15.142050 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=2.188937
I20260812 06:20:15.168192 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.026s	user 0.014s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4738,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.168919 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=1.000000
I20260812 06:20:15.387210 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.218s	user 0.128s	sys 0.080s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":382,"lbm_read_time_us":14079,"lbm_reads_lt_1ms":572,"lbm_write_time_us":36852,"lbm_writes_lt_1ms":543,"mutex_wait_us":32,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":42112,"update_count":2500}
I20260812 06:20:15.388067 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=14.095187
I20260812 06:20:15.444855 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.057s	user 0.035s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25771,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:15.445544 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=2.188937
I20260812 06:20:15.458274 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.013s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4706,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.459172 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=1.000000
I20260812 06:20:15.664407 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.205s	user 0.129s	sys 0.067s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":490,"lbm_read_time_us":13963,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34156,"lbm_writes_lt_1ms":543,"mutex_wait_us":106,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:15.665302 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=11.118625
I20260812 06:20:15.715507 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.050s	user 0.033s	sys 0.016s Metrics: {"bytes_written":12717738,"delete_count":0,"lbm_write_time_us":21745,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:15.716300 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=2.188937
I20260812 06:20:15.745508 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.029s	user 0.010s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6288,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:15.746258 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=2.188937
I20260812 06:20:15.760110 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.014s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5267,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.760754 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=1.000000
I20260812 06:20:15.941479 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.180s	user 0.128s	sys 0.051s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733837,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":689,"lbm_read_time_us":13615,"lbm_reads_lt_1ms":573,"lbm_write_time_us":38726,"lbm_writes_lt_1ms":543,"mutex_wait_us":337,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:20:15.942401 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=10.126437
I20260812 06:20:15.983424 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.041s	user 0.028s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17879,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:15.984282 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=2.188937
I20260812 06:20:16.000241 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5595,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.001039 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=1.000000
I20260812 06:20:16.147243 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.146s	user 0.114s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":218,"lbm_read_time_us":11455,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28363,"lbm_writes_lt_1ms":443,"mutex_wait_us":49,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":102144,"update_count":2000}
I20260812 06:20:16.148139 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=10.126437
I20260812 06:20:16.194121 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.046s	user 0.024s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19413,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:16.194782 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=2.188937
I20260812 06:20:16.207458 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.012s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4882,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.208395 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushMRSOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=1.000000
I20260812 06:20:16.246659 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushMRSOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.038s	user 0.036s	sys 0.000s Metrics: {"bytes_written":1234476,"cfile_init":1,"dirs.queue_time_us":80,"dirs.run_cpu_time_us":249,"dirs.run_wall_time_us":1258,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2602,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30,"spinlock_wait_cycles":2816}
I20260812 06:20:16.247567 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling LogGCOp(8f4fb40221f74532a2a8dd9307ec7e74): free 121006665 bytes of WAL
I20260812 06:20:16.247802 10608 log_reader.cc:385] T 8f4fb40221f74532a2a8dd9307ec7e74: removed 12 log segments from log reader
I20260812 06:20:16.247848 10608 log.cc:1079] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/8f4fb40221f74532a2a8dd9307ec7e74/wal-000000026 (ops 123-127)
I20260812 06:20:16.247901 10608 log.cc:1079] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/8f4fb40221f74532a2a8dd9307ec7e74/wal-000000027 (ops 128-132)
I20260812 06:20:16.247946 10608 log.cc:1079] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/8f4fb40221f74532a2a8dd9307ec7e74/wal-000000028 (ops 133-137)
I20260812 06:20:16.248014 10608 log.cc:1079] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/8f4fb40221f74532a2a8dd9307ec7e74/wal-000000029 (ops 138-142)
I20260812 06:20:16.248052 10608 log.cc:1079] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/8f4fb40221f74532a2a8dd9307ec7e74/wal-000000030 (ops 143-146)
I20260812 06:20:16.248107 10608 log.cc:1079] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/8f4fb40221f74532a2a8dd9307ec7e74/wal-000000031 (ops 147-151)
I20260812 06:20:16.248147 10608 log.cc:1079] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/8f4fb40221f74532a2a8dd9307ec7e74/wal-000000032 (ops 152-156)
I20260812 06:20:16.248188 10608 log.cc:1079] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/8f4fb40221f74532a2a8dd9307ec7e74/wal-000000033 (ops 157-161)
I20260812 06:20:16.248227 10608 log.cc:1079] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/8f4fb40221f74532a2a8dd9307ec7e74/wal-000000034 (ops 162-166)
I20260812 06:20:16.248266 10608 log.cc:1079] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/8f4fb40221f74532a2a8dd9307ec7e74/wal-000000035 (ops 167-171)
I20260812 06:20:16.248306 10608 log.cc:1079] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/8f4fb40221f74532a2a8dd9307ec7e74/wal-000000036 (ops 172-176)
I20260812 06:20:16.248344 10608 log.cc:1079] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: Deleting log segment in path: /tmp/dist-test-taskspnXiw/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515604142778-10160-0/minicluster-data/ts-0-root/wals/8f4fb40221f74532a2a8dd9307ec7e74/wal-000000037 (ops 177-181)
I20260812 06:20:16.280514 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: LogGCOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.033s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:20:16.280954 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling UndoDeltaBlockGCOp(8f4fb40221f74532a2a8dd9307ec7e74): 472 bytes on disk
I20260812 06:20:16.281389 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: UndoDeltaBlockGCOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:20:16.282225 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=3.181125
I20260812 06:20:16.297621 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":5333393,"delete_count":0,"lbm_write_time_us":6497,"lbm_writes_lt_1ms":133,"reinsert_count":0,"update_count":650}
I20260812 06:20:16.298237 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=1.196750
I20260812 06:20:16.311578 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":2871905,"delete_count":0,"lbm_write_time_us":4503,"lbm_writes_lt_1ms":73,"reinsert_count":0,"update_count":350}
I20260812 06:20:16.312310 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=1.000000
I20260812 06:20:16.523238 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.211s	user 0.148s	sys 0.059s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836348,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":372,"lbm_read_time_us":15595,"lbm_reads_lt_1ms":666,"lbm_write_time_us":42913,"lbm_writes_lt_1ms":643,"mutex_wait_us":43,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1408,"thread_start_us":165,"threads_started":1,"update_count":3000}
I20260812 06:20:16.524214 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=14.095187
I20260812 06:20:16.589736 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.065s	user 0.043s	sys 0.014s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":27416,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:16.590395 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=2.188937
I20260812 06:20:16.603775 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.013s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4700,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.604414 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=1.000000
I20260812 06:20:16.789494 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.185s	user 0.128s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":877,"lbm_read_time_us":14009,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35103,"lbm_writes_lt_1ms":543,"mutex_wait_us":423,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:20:16.790292 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=11.118625
I20260812 06:20:16.823817 10160 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.908s	user 2.128s	sys 0.272s
I20260812 06:20:16.827944 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.037s	user 0.032s	sys 0.004s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17927,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:16.828598 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=2.188937
I20260812 06:20:16.842058 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: FlushDeltaMemStoresOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.013s	user 0.005s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5462,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:16.842756 10701 maintenance_manager.cc:419] P 08e309e4e721480085074f9da5fcd5a5: Scheduling MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74): perf score=1.000000
I20260812 06:20:16.879650 10160 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.055s	user 0.006s	sys 0.000s
I20260812 06:20:16.880574 10160 tablet_server.cc:179] TabletServer@127.9.236.1:0 shutting down...
I20260812 06:20:16.980854 10608 maintenance_manager.cc:643] P 08e309e4e721480085074f9da5fcd5a5: MajorDeltaCompactionOp(8f4fb40221f74532a2a8dd9307ec7e74) complete. Timing: real 0.138s	user 0.098s	sys 0.040s Metrics: {"cfile_cache_hit":30,"cfile_cache_hit_bytes":4221425,"cfile_cache_miss":402,"cfile_cache_miss_bytes":16409878,"cfile_init":4,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1611,"lbm_read_time_us":8451,"lbm_reads_lt_1ms":418,"lbm_write_time_us":24770,"lbm_writes_lt_1ms":443,"mutex_wait_us":445,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":2000}
I20260812 06:20:16.981746 10160 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:16.982002 10160 tablet_replica.cc:333] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5: stopping tablet replica
I20260812 06:20:16.982196 10160 raft_consensus.cc:2243] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:16.982422 10160 raft_consensus.cc:2272] T 8f4fb40221f74532a2a8dd9307ec7e74 P 08e309e4e721480085074f9da5fcd5a5 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:16.997650 10160 tablet_server.cc:196] TabletServer@127.9.236.1:0 shutdown complete.
I20260812 06:20:17.020838 10160 master.cc:562] Master@127.9.236.62:44379 shutting down...
I20260812 06:20:17.024569 10160 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 59333c3ead3241559dee95e1e958dfa2 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:17.024801 10160 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 59333c3ead3241559dee95e1e958dfa2 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:17.024859 10160 tablet_replica.cc:333] T 00000000000000000000000000000000 P 59333c3ead3241559dee95e1e958dfa2: stopping tablet replica
I20260812 06:20:17.037745 10160 master.cc:584] Master@127.9.236.62:44379 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (6486 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (12993 ms total)

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