[==========] 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:16:36.937611  1951 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.1.231.254:42359
I20260812 06:16:36.938555  1951 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:16:36.939116  1951 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:36.945541  1965 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:16:36.945669  1963 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:16:36.945858  1962 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:16:36.946044  1951 server_base.cc:1061] running on GCE node
I20260812 06:16:36.946477  1951 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:36.946579  1951 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:16:36.946623  1951 hybrid_clock.cc:648] HybridClock initialized: now 1786515396946619 us; error 0 us; skew 500 ppm
I20260812 06:16:36.948288  1951 webserver.cc:533] Webserver started at http://127.1.231.254:39329/ using document root <none> and password file <none>
I20260812 06:16:36.948812  1951 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:36.948873  1951 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:36.949132  1951 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:36.950739  1951 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/master-0-root/instance:
uuid: "13be22375673457788176ce9a4510c48"
format_stamp: "Formatted at 2026-08-12 06:16:36 on dist-test-slave-k5rr"
I20260812 06:16:36.954234  1951 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.002s	sys 0.002s
I20260812 06:16:36.956377  1972 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:16:36.957526  1951 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:36.957633  1951 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/master-0-root
uuid: "13be22375673457788176ce9a4510c48"
format_stamp: "Formatted at 2026-08-12 06:16:36 on dist-test-slave-k5rr"
I20260812 06:16:36.957717  1951 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-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:16:36.970763  1951 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:36.971323  1951 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:16:36.971485  1951 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:36.979038  1951 rpc_server.cc:307] RPC server started. Bound to: 127.1.231.254:42359
I20260812 06:16:36.979059  2058 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.1.231.254:42359 every 8 connection(s)
I20260812 06:16:36.981760  2059 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:16:36.989751  2059 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 13be22375673457788176ce9a4510c48: Bootstrap starting.
I20260812 06:16:36.993188  2059 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 13be22375673457788176ce9a4510c48: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:36.994439  2059 log.cc:826] T 00000000000000000000000000000000 P 13be22375673457788176ce9a4510c48: Log is configured to *not* fsync() on all Append() calls
I20260812 06:16:36.996681  2059 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 13be22375673457788176ce9a4510c48: No bootstrap required, opened a new log
I20260812 06:16:37.000878  2059 raft_consensus.cc:359] T 00000000000000000000000000000000 P 13be22375673457788176ce9a4510c48 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "13be22375673457788176ce9a4510c48" member_type: VOTER }
I20260812 06:16:37.001113  2059 raft_consensus.cc:385] T 00000000000000000000000000000000 P 13be22375673457788176ce9a4510c48 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:37.001183  2059 raft_consensus.cc:740] T 00000000000000000000000000000000 P 13be22375673457788176ce9a4510c48 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 13be22375673457788176ce9a4510c48, State: Initialized, Role: FOLLOWER
I20260812 06:16:37.001950  2059 consensus_queue.cc:260] T 00000000000000000000000000000000 P 13be22375673457788176ce9a4510c48 [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: "13be22375673457788176ce9a4510c48" member_type: VOTER }
I20260812 06:16:37.002161  2059 raft_consensus.cc:399] T 00000000000000000000000000000000 P 13be22375673457788176ce9a4510c48 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:37.002233  2059 raft_consensus.cc:493] T 00000000000000000000000000000000 P 13be22375673457788176ce9a4510c48 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:37.002362  2059 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 13be22375673457788176ce9a4510c48 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:37.003523  2059 raft_consensus.cc:515] T 00000000000000000000000000000000 P 13be22375673457788176ce9a4510c48 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "13be22375673457788176ce9a4510c48" member_type: VOTER }
I20260812 06:16:37.004091  2059 leader_election.cc:304] T 00000000000000000000000000000000 P 13be22375673457788176ce9a4510c48 [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: 13be22375673457788176ce9a4510c48; no voters: 
I20260812 06:16:37.004509  2059 leader_election.cc:290] T 00000000000000000000000000000000 P 13be22375673457788176ce9a4510c48 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:37.004642  2064 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 13be22375673457788176ce9a4510c48 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:37.004923  2064 raft_consensus.cc:697] T 00000000000000000000000000000000 P 13be22375673457788176ce9a4510c48 [term 1 LEADER]: Becoming Leader. State: Replica: 13be22375673457788176ce9a4510c48, State: Running, Role: LEADER
I20260812 06:16:37.005383  2064 consensus_queue.cc:237] T 00000000000000000000000000000000 P 13be22375673457788176ce9a4510c48 [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: "13be22375673457788176ce9a4510c48" member_type: VOTER }
I20260812 06:16:37.005746  2059 sys_catalog.cc:565] T 00000000000000000000000000000000 P 13be22375673457788176ce9a4510c48 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:37.007148  2066 sys_catalog.cc:455] T 00000000000000000000000000000000 P 13be22375673457788176ce9a4510c48 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "13be22375673457788176ce9a4510c48" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "13be22375673457788176ce9a4510c48" member_type: VOTER } }
I20260812 06:16:37.007335  2066 sys_catalog.cc:458] T 00000000000000000000000000000000 P 13be22375673457788176ce9a4510c48 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:37.007603  2066 sys_catalog.cc:455] T 00000000000000000000000000000000 P 13be22375673457788176ce9a4510c48 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 13be22375673457788176ce9a4510c48. Latest consensus state: current_term: 1 leader_uuid: "13be22375673457788176ce9a4510c48" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "13be22375673457788176ce9a4510c48" member_type: VOTER } }
I20260812 06:16:37.007728  2066 sys_catalog.cc:458] T 00000000000000000000000000000000 P 13be22375673457788176ce9a4510c48 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:37.007754  2074 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:37.010465  2074 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:37.010751  1951 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:37.016209  2074 catalog_manager.cc:1383] Generated new cluster ID: 4ab2e98452bf4ac49a9548d890f980a9
I20260812 06:16:37.016290  2074 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:37.035955  2074 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:37.037181  2074 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:37.057744  2074 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 13be22375673457788176ce9a4510c48: Generated new TSK 0
I20260812 06:16:37.058693  2074 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:37.075796  1951 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:37.079053  2096 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:16:37.079350  1951 server_base.cc:1061] running on GCE node
W20260812 06:16:37.079137  2102 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:16:37.079326  2098 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:16:37.079806  1951 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:37.079864  1951 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:16:37.079887  1951 hybrid_clock.cc:648] HybridClock initialized: now 1786515397079887 us; error 0 us; skew 500 ppm
I20260812 06:16:37.080828  1951 webserver.cc:533] Webserver started at http://127.1.231.193:37059/ using document root <none> and password file <none>
I20260812 06:16:37.080998  1951 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:37.081081  1951 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:37.081151  1951 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:37.081580  1951 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/instance:
uuid: "3f553c614d1f4fdbbe8dad00da05c8bf"
format_stamp: "Formatted at 2026-08-12 06:16:37 on dist-test-slave-k5rr"
I20260812 06:16:37.083432  1951 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:37.084523  2111 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:16:37.084779  1951 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:37.084899  1951 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root
uuid: "3f553c614d1f4fdbbe8dad00da05c8bf"
format_stamp: "Formatted at 2026-08-12 06:16:37 on dist-test-slave-k5rr"
I20260812 06:16:37.085041  1951 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-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:16:37.091879  1951 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:37.092387  1951 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:37.093024  1951 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:37.094062  1951 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:37.094170  1951 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:37.094287  1951 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:37.094358  1951 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:37.101033  1951 rpc_server.cc:307] RPC server started. Bound to: 127.1.231.193:43399
I20260812 06:16:37.101086  2226 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.1.231.193:43399 every 8 connection(s)
I20260812 06:16:37.116058  2229 heartbeater.cc:344] Connected to a master server at 127.1.231.254:42359
I20260812 06:16:37.116331  2229 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:37.116891  2229 heartbeater.cc:507] Master 127.1.231.254:42359 requested a full tablet report, sending...
I20260812 06:16:37.118589  1997 ts_manager.cc:194] Registered new tserver with Master: 3f553c614d1f4fdbbe8dad00da05c8bf (127.1.231.193:43399)
I20260812 06:16:37.119453  1951 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.017666988s
I20260812 06:16:37.120194  1997 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:38568
I20260812 06:16:37.130553  1997 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:38576:
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:16:37.146646  2163 tablet_service.cc:1511] Processing CreateTablet for tablet 78119faed6524283b74afb1508ec16d4 (DEFAULT_TABLE table=heavy-update-compaction-test [id=1cc80dce0d4b4befb8231d1970e3fc59]), partition=
I20260812 06:16:37.147163  2163 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 78119faed6524283b74afb1508ec16d4. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:37.150557  2250 tablet_bootstrap.cc:492] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Bootstrap starting.
I20260812 06:16:37.152074  2250 tablet_bootstrap.cc:654] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:37.153455  2250 tablet_bootstrap.cc:492] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: No bootstrap required, opened a new log
I20260812 06:16:37.153568  2250 ts_tablet_manager.cc:1403] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:16:37.154157  2250 raft_consensus.cc:359] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3f553c614d1f4fdbbe8dad00da05c8bf" member_type: VOTER last_known_addr { host: "127.1.231.193" port: 43399 } }
I20260812 06:16:37.154345  2250 raft_consensus.cc:385] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:37.154404  2250 raft_consensus.cc:740] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3f553c614d1f4fdbbe8dad00da05c8bf, State: Initialized, Role: FOLLOWER
I20260812 06:16:37.154536  2250 consensus_queue.cc:260] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf [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: "3f553c614d1f4fdbbe8dad00da05c8bf" member_type: VOTER last_known_addr { host: "127.1.231.193" port: 43399 } }
I20260812 06:16:37.154629  2250 raft_consensus.cc:399] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:37.154711  2250 raft_consensus.cc:493] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:37.154773  2250 raft_consensus.cc:3060] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:37.155766  2250 raft_consensus.cc:515] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3f553c614d1f4fdbbe8dad00da05c8bf" member_type: VOTER last_known_addr { host: "127.1.231.193" port: 43399 } }
I20260812 06:16:37.155920  2250 leader_election.cc:304] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf [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: 3f553c614d1f4fdbbe8dad00da05c8bf; no voters: 
I20260812 06:16:37.156113  2250 leader_election.cc:290] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:37.156248  2254 raft_consensus.cc:2804] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:37.156495  2254 raft_consensus.cc:697] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf [term 1 LEADER]: Becoming Leader. State: Replica: 3f553c614d1f4fdbbe8dad00da05c8bf, State: Running, Role: LEADER
I20260812 06:16:37.156585  2250 ts_tablet_manager.cc:1434] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:16:37.156708  2229 heartbeater.cc:499] Master 127.1.231.254:42359 was elected leader, sending a full tablet report...
I20260812 06:16:37.156662  2254 consensus_queue.cc:237] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf [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: "3f553c614d1f4fdbbe8dad00da05c8bf" member_type: VOTER last_known_addr { host: "127.1.231.193" port: 43399 } }
I20260812 06:16:37.159662  1997 catalog_manager.cc:5719] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf reported cstate change: term changed from 0 to 1, leader changed from <none> to 3f553c614d1f4fdbbe8dad00da05c8bf (127.1.231.193). New cstate: current_term: 1 leader_uuid: "3f553c614d1f4fdbbe8dad00da05c8bf" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3f553c614d1f4fdbbe8dad00da05c8bf" member_type: VOTER last_known_addr { host: "127.1.231.193" port: 43399 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:37.224804  1951 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.059s	user 0.028s	sys 0.003s
I20260812 06:16:37.352157  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushMRSOp(78119faed6524283b74afb1508ec16d4): perf score=19.054940
I20260812 06:16:37.545650  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushMRSOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.193s	user 0.147s	sys 0.040s Metrics: {"bytes_written":13210026,"cfile_init":1,"compiler_manager_pool.queue_time_us":191,"delete_count":0,"dirs.queue_time_us":89,"dirs.run_cpu_time_us":219,"dirs.run_wall_time_us":1084,"drs_written":1,"lbm_read_time_us":82,"lbm_reads_lt_1ms":4,"lbm_write_time_us":47327,"lbm_writes_lt_1ms":779,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":3940224,"thread_start_us":103,"threads_started":1,"update_count":1610}
I20260812 06:16:37.546766  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling LogGCOp(78119faed6524283b74afb1508ec16d4): free 20743880 bytes of WAL
I20260812 06:16:37.547122  2119 log_reader.cc:385] T 78119faed6524283b74afb1508ec16d4: removed 2 log segments from log reader
I20260812 06:16:37.547199  2119 log.cc:1079] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/78119faed6524283b74afb1508ec16d4/wal-000000001 (ops 1-6)
I20260812 06:16:37.547312  2119 log.cc:1079] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/78119faed6524283b74afb1508ec16d4/wal-000000002 (ops 7-11)
I20260812 06:16:37.551904  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: LogGCOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:16:37.552222  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=2.188937
I20260812 06:16:37.573505  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.021s	user 0.013s	sys 0.007s Metrics: {"bytes_written":3610359,"delete_count":0,"lbm_write_time_us":5193,"lbm_writes_lt_1ms":91,"reinsert_count":0,"update_count":440}
I20260812 06:16:37.573982  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=2.188937
I20260812 06:16:37.587527  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4887,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:37.588106  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling MajorDeltaCompactionOp(78119faed6524283b74afb1508ec16d4): perf score=1.000000
I20260812 06:16:37.748215  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: MajorDeltaCompactionOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.160s	user 0.104s	sys 0.056s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774790,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":508,"lbm_read_time_us":11401,"lbm_reads_lt_1ms":573,"lbm_write_time_us":26463,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":279,"threads_started":5,"update_count":2500}
I20260812 06:16:37.748705  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling UndoDeltaBlockGCOp(78119faed6524283b74afb1508ec16d4): 16411392 bytes on disk
I20260812 06:16:37.749155  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: UndoDeltaBlockGCOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:16:37.749537  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=10.126437
I20260812 06:16:37.793867  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.044s	user 0.020s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19620,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:16:37.794401  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=2.188937
I20260812 06:16:37.809312  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5518,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:37.809820  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling MajorDeltaCompactionOp(78119faed6524283b74afb1508ec16d4): perf score=1.000000
I20260812 06:16:37.919823  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: MajorDeltaCompactionOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.110s	user 0.069s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":588,"lbm_read_time_us":8135,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20687,"lbm_writes_lt_1ms":443,"mutex_wait_us":302,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:16:37.920264  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=10.126437
I20260812 06:16:37.957607  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.037s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16975,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":300,"reinsert_count":0,"update_count":1500}
I20260812 06:16:37.958087  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=2.188937
I20260812 06:16:37.968259  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3816,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:37.968998  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling MajorDeltaCompactionOp(78119faed6524283b74afb1508ec16d4): perf score=1.000000
I20260812 06:16:38.090894  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: MajorDeltaCompactionOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.122s	user 0.096s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":307,"lbm_read_time_us":8776,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23104,"lbm_writes_lt_1ms":443,"mutex_wait_us":44,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9728,"update_count":2000}
I20260812 06:16:38.091346  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=10.126437
I20260812 06:16:38.136777  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.045s	user 0.025s	sys 0.004s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":13988,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:38.137356  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=2.188937
I20260812 06:16:38.149206  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4176,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:38.149755  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling MajorDeltaCompactionOp(78119faed6524283b74afb1508ec16d4): perf score=1.000000
I20260812 06:16:38.278908  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: MajorDeltaCompactionOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.129s	user 0.108s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":811,"lbm_read_time_us":9387,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24656,"lbm_writes_lt_1ms":443,"mutex_wait_us":333,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2000}
I20260812 06:16:38.279448  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=11.118625
I20260812 06:16:38.314456  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.035s	user 0.021s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":12212,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:38.315186  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=2.188937
I20260812 06:16:38.326347  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3752,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:38.326825  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling MajorDeltaCompactionOp(78119faed6524283b74afb1508ec16d4): perf score=1.000000
I20260812 06:16:38.461198  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: MajorDeltaCompactionOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.134s	user 0.098s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":203,"lbm_read_time_us":10883,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21262,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:38.461961  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=10.126437
I20260812 06:16:38.499150  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.037s	user 0.028s	sys 0.004s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":14647,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:38.499637  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=2.188937
I20260812 06:16:38.512220  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.012s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4929,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:38.512645  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling MajorDeltaCompactionOp(78119faed6524283b74afb1508ec16d4): perf score=1.000000
I20260812 06:16:38.629985  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: MajorDeltaCompactionOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.117s	user 0.093s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":909,"lbm_read_time_us":8290,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23194,"lbm_writes_lt_1ms":443,"mutex_wait_us":279,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:38.630479  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=10.126437
I20260812 06:16:38.667182  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.037s	user 0.013s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13454,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:38.667666  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=2.188937
I20260812 06:16:38.677304  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.009s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3548,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:38.677999  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushMRSOp(78119faed6524283b74afb1508ec16d4): perf score=1.000000
I20260812 06:16:38.708087  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushMRSOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.030s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":52,"dirs.run_cpu_time_us":187,"dirs.run_wall_time_us":1086,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1837,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:16:38.709061  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling LogGCOp(78119faed6524283b74afb1508ec16d4): free 112239315 bytes of WAL
I20260812 06:16:38.709309  2119 log_reader.cc:385] T 78119faed6524283b74afb1508ec16d4: removed 11 log segments from log reader
I20260812 06:16:38.709362  2119 log.cc:1079] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/78119faed6524283b74afb1508ec16d4/wal-000000003 (ops 12-16)
I20260812 06:16:38.709388  2119 log.cc:1079] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/78119faed6524283b74afb1508ec16d4/wal-000000004 (ops 17-20)
I20260812 06:16:38.709408  2119 log.cc:1079] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/78119faed6524283b74afb1508ec16d4/wal-000000005 (ops 21-25)
I20260812 06:16:38.709439  2119 log.cc:1079] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/78119faed6524283b74afb1508ec16d4/wal-000000006 (ops 26-30)
I20260812 06:16:38.709473  2119 log.cc:1079] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/78119faed6524283b74afb1508ec16d4/wal-000000007 (ops 31-35)
I20260812 06:16:38.709494  2119 log.cc:1079] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/78119faed6524283b74afb1508ec16d4/wal-000000008 (ops 36-40)
I20260812 06:16:38.709525  2119 log.cc:1079] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/78119faed6524283b74afb1508ec16d4/wal-000000009 (ops 41-45)
I20260812 06:16:38.709558  2119 log.cc:1079] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/78119faed6524283b74afb1508ec16d4/wal-000000010 (ops 46-50)
I20260812 06:16:38.709589  2119 log.cc:1079] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/78119faed6524283b74afb1508ec16d4/wal-000000011 (ops 51-55)
I20260812 06:16:38.709619  2119 log.cc:1079] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/78119faed6524283b74afb1508ec16d4/wal-000000012 (ops 56-60)
I20260812 06:16:38.709651  2119 log.cc:1079] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/78119faed6524283b74afb1508ec16d4/wal-000000013 (ops 61-65)
I20260812 06:16:38.730435  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: LogGCOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.021s	user 0.000s	sys 0.020s Metrics: {}
I20260812 06:16:38.730789  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=3.181125
I20260812 06:16:38.750504  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.020s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6312,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:38.750896  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling LogGCOp(78119faed6524283b74afb1508ec16d4): free 12017932 bytes of WAL
I20260812 06:16:38.751081  2119 log_reader.cc:385] T 78119faed6524283b74afb1508ec16d4: removed 1 log segments from log reader
I20260812 06:16:38.751124  2119 log.cc:1079] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/78119faed6524283b74afb1508ec16d4/wal-000000014 (ops 66-70)
I20260812 06:16:38.753226  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: LogGCOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.002s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:16:38.753504  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=2.188937
I20260812 06:16:38.762494  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.009s	user 0.006s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3112,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:38.763104  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling UndoDeltaBlockGCOp(78119faed6524283b74afb1508ec16d4): 462 bytes on disk
I20260812 06:16:38.763530  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: UndoDeltaBlockGCOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:16:38.764020  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling MajorDeltaCompactionOp(78119faed6524283b74afb1508ec16d4): perf score=1.000000
I20260812 06:16:38.920939  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: MajorDeltaCompactionOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.157s	user 0.116s	sys 0.039s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877329,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":162,"lbm_read_time_us":10797,"lbm_reads_lt_1ms":674,"lbm_write_time_us":29406,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":73,"threads_started":1,"update_count":3000}
I20260812 06:16:38.921445  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=14.095187
I20260812 06:16:38.969911  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.048s	user 0.020s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17248,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:38.970396  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=2.188937
I20260812 06:16:38.981060  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3765,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:38.981899  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling MajorDeltaCompactionOp(78119faed6524283b74afb1508ec16d4): perf score=1.000000
I20260812 06:16:39.123934  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: MajorDeltaCompactionOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.142s	user 0.119s	sys 0.021s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":177,"lbm_read_time_us":9699,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27160,"lbm_writes_lt_1ms":543,"mutex_wait_us":59,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5632,"update_count":2500}
I20260812 06:16:39.124413  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=11.118625
I20260812 06:16:39.157766  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.033s	user 0.021s	sys 0.011s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":14141,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:39.158420  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=2.188937
I20260812 06:16:39.174973  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5691,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:39.175416  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling MajorDeltaCompactionOp(78119faed6524283b74afb1508ec16d4): perf score=1.000000
I20260812 06:16:39.299904  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: MajorDeltaCompactionOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.124s	user 0.090s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":166,"lbm_read_time_us":9231,"lbm_reads_lt_1ms":468,"lbm_write_time_us":23727,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16256,"update_count":2000}
I20260812 06:16:39.300745  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=10.126437
I20260812 06:16:39.333192  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.032s	user 0.019s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13348,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:39.333627  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=2.188937
I20260812 06:16:39.343745  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3808,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:39.344230  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling MajorDeltaCompactionOp(78119faed6524283b74afb1508ec16d4): perf score=1.000000
I20260812 06:16:39.503582  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: MajorDeltaCompactionOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.159s	user 0.084s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":518,"lbm_read_time_us":8274,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23476,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14080,"update_count":2000}
I20260812 06:16:39.504539  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=10.126437
I20260812 06:16:39.697503  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.193s	user 0.035s	sys 0.004s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16989,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:39.698156  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=15.087375
I20260812 06:16:39.796567  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.098s	user 0.032s	sys 0.008s Metrics: {"bytes_written":17558580,"delete_count":0,"lbm_write_time_us":18670,"lbm_writes_lt_1ms":431,"mutex_wait_us":74,"reinsert_count":0,"update_count":2140}
I20260812 06:16:39.797183  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=9.134250
I20260812 06:16:39.897771  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.100s	user 0.026s	sys 0.007s Metrics: {"bytes_written":11158823,"delete_count":0,"lbm_write_time_us":14143,"lbm_writes_lt_1ms":275,"reinsert_count":0,"update_count":1360}
I20260812 06:16:39.898366  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=7.149875
I20260812 06:16:40.005177  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.106s	user 0.015s	sys 0.011s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":8242,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:16:40.005785  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=10.126437
I20260812 06:16:40.096771  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.091s	user 0.022s	sys 0.004s Metrics: {"bytes_written":11897249,"delete_count":0,"lbm_write_time_us":11976,"lbm_writes_lt_1ms":293,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":1450}
I20260812 06:16:40.097299  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=6.157687
I20260812 06:16:40.198167  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.101s	user 0.023s	sys 0.003s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":11005,"lbm_writes_lt_1ms":203,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":1000}
I20260812 06:16:40.199072  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=6.157687
I20260812 06:16:40.301992  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.103s	user 0.005s	sys 0.016s Metrics: {"bytes_written":8205079,"delete_count":0,"lbm_write_time_us":8834,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:40.302558  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=10.126437
I20260812 06:16:40.404465  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.102s	user 0.017s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18322,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:40.405622  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=6.157687
I20260812 06:16:40.505041  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.099s	user 0.020s	sys 0.001s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9876,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:40.505720  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=7.149875
I20260812 06:16:40.606082  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.100s	user 0.012s	sys 0.015s Metrics: {"bytes_written":9353756,"delete_count":0,"lbm_write_time_us":11352,"lbm_writes_lt_1ms":231,"mutex_wait_us":143,"reinsert_count":0,"update_count":1140}
I20260812 06:16:40.606782  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=9.134250
I20260812 06:16:40.706552  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.100s	user 0.026s	sys 0.008s Metrics: {"bytes_written":11158823,"delete_count":0,"lbm_write_time_us":14766,"lbm_writes_lt_1ms":275,"reinsert_count":0,"update_count":1360}
I20260812 06:16:40.707270  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=7.149875
I20260812 06:16:40.803428  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.096s	user 0.026s	sys 0.000s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":11441,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:16:40.803954  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=8.142062
I20260812 06:16:40.903190  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.099s	user 0.021s	sys 0.004s Metrics: {"bytes_written":9517848,"delete_count":0,"lbm_write_time_us":10622,"lbm_writes_lt_1ms":235,"reinsert_count":0,"update_count":1160}
I20260812 06:16:40.903761  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=9.134250
I20260812 06:16:40.998469  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.095s	user 0.017s	sys 0.012s Metrics: {"bytes_written":10584487,"delete_count":0,"lbm_write_time_us":12411,"lbm_writes_lt_1ms":261,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":1290}
I20260812 06:16:40.999186  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=6.157687
I20260812 06:16:41.097237  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.098s	user 0.019s	sys 0.008s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10948,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:41.097802  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=7.149875
I20260812 06:16:41.194180  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.096s	user 0.012s	sys 0.015s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":11555,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:16:41.194845  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=7.149875
I20260812 06:16:41.295482  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.100s	user 0.016s	sys 0.008s Metrics: {"bytes_written":8574299,"delete_count":0,"lbm_write_time_us":10415,"lbm_writes_lt_1ms":212,"reinsert_count":0,"update_count":1045}
I20260812 06:16:41.296068  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=10.126437
I20260812 06:16:41.398334  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.102s	user 0.021s	sys 0.019s Metrics: {"bytes_written":11528038,"delete_count":0,"lbm_write_time_us":15704,"lbm_writes_lt_1ms":284,"reinsert_count":0,"update_count":1405}
I20260812 06:16:41.399014  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=6.157687
I20260812 06:16:41.493175  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.094s	user 0.016s	sys 0.008s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9974,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:41.493700  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=6.157687
I20260812 06:16:41.595070  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.101s	user 0.019s	sys 0.005s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10555,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:41.595896  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=6.157687
I20260812 06:16:41.616155  1951 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.391s	user 1.621s	sys 0.109s
I20260812 06:16:41.696460  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.100s	user 0.009s	sys 0.012s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9467,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:41.697219  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4): perf score=2.188937
I20260812 06:16:41.796289  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushDeltaMemStoresOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.099s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3829,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:41.796952  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling FlushMRSOp(78119faed6524283b74afb1508ec16d4): perf score=1.195565
I20260812 06:16:41.897346  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: FlushMRSOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.100s	user 0.042s	sys 0.005s Metrics: {"bytes_written":2750901,"cfile_init":1,"dirs.queue_time_us":206,"dirs.run_cpu_time_us":249,"dirs.run_wall_time_us":55461,"drs_written":1,"lbm_read_time_us":34,"lbm_reads_lt_1ms":4,"lbm_write_time_us":5008,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":47,"peak_mem_usage":0,"rows_written":67,"thread_start_us":85,"threads_started":1}
I20260812 06:16:41.898339  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling LogGCOp(78119faed6524283b74afb1508ec16d4): free 254031113 bytes of WAL
I20260812 06:16:41.898640  2119 log_reader.cc:385] T 78119faed6524283b74afb1508ec16d4: removed 25 log segments from log reader
I20260812 06:16:41.898702  2119 log.cc:1079] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/78119faed6524283b74afb1508ec16d4/wal-000000015 (ops 71-75)
I20260812 06:16:41.898763  2119 log.cc:1079] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/78119faed6524283b74afb1508ec16d4/wal-000000016 (ops 76-80)
I20260812 06:16:41.898805  2119 log.cc:1079] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/78119faed6524283b74afb1508ec16d4/wal-000000017 (ops 81-85)
I20260812 06:16:41.898840  2119 log.cc:1079] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/78119faed6524283b74afb1508ec16d4/wal-000000018 (ops 86-90)
I20260812 06:16:41.898873  2119 log.cc:1079] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/78119faed6524283b74afb1508ec16d4/wal-000000019 (ops 91-94)
I20260812 06:16:41.898904  2119 log.cc:1079] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/78119faed6524283b74afb1508ec16d4/wal-000000020 (ops 95-99)
I20260812 06:16:41.898996  2119 log.cc:1079] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/78119faed6524283b74afb1508ec16d4/wal-000000021 (ops 100-104)
I20260812 06:16:41.899045  2119 log.cc:1079] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/78119faed6524283b74afb1508ec16d4/wal-000000022 (ops 105-111)
I20260812 06:16:41.899118  2119 log.cc:1079] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/78119faed6524283b74afb1508ec16d4/wal-000000023 (ops 112-116)
I20260812 06:16:41.899161  2119 log.cc:1079] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/78119faed6524283b74afb1508ec16d4/wal-000000024 (ops 117-120)
I20260812 06:16:41.899233  2119 log.cc:1079] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/78119faed6524283b74afb1508ec16d4/wal-000000025 (ops 121-125)
I20260812 06:16:41.899271  2119 log.cc:1079] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/78119faed6524283b74afb1508ec16d4/wal-000000026 (ops 126-130)
I20260812 06:16:41.899322  2119 log.cc:1079] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/78119faed6524283b74afb1508ec16d4/wal-000000027 (ops 131-135)
I20260812 06:16:41.899356  2119 log.cc:1079] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/78119faed6524283b74afb1508ec16d4/wal-000000028 (ops 136-140)
I20260812 06:16:41.899379  2119 log.cc:1079] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/78119faed6524283b74afb1508ec16d4/wal-000000029 (ops 141-145)
I20260812 06:16:41.899401  2119 log.cc:1079] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/78119faed6524283b74afb1508ec16d4/wal-000000030 (ops 146-150)
I20260812 06:16:41.899422  2119 log.cc:1079] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/78119faed6524283b74afb1508ec16d4/wal-000000031 (ops 151-155)
I20260812 06:16:41.899444  2119 log.cc:1079] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/78119faed6524283b74afb1508ec16d4/wal-000000032 (ops 156-160)
I20260812 06:16:41.899466  2119 log.cc:1079] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/78119faed6524283b74afb1508ec16d4/wal-000000033 (ops 161-164)
I20260812 06:16:41.899487  2119 log.cc:1079] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/78119faed6524283b74afb1508ec16d4/wal-000000034 (ops 165-169)
I20260812 06:16:41.899507  2119 log.cc:1079] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/78119faed6524283b74afb1508ec16d4/wal-000000035 (ops 170-174)
I20260812 06:16:41.899528  2119 log.cc:1079] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/78119faed6524283b74afb1508ec16d4/wal-000000036 (ops 175-178)
I20260812 06:16:41.899554  2119 log.cc:1079] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/78119faed6524283b74afb1508ec16d4/wal-000000037 (ops 179-183)
I20260812 06:16:41.899575  2119 log.cc:1079] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/78119faed6524283b74afb1508ec16d4/wal-000000038 (ops 184-188)
I20260812 06:16:41.899596  2119 log.cc:1079] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/78119faed6524283b74afb1508ec16d4/wal-000000039 (ops 189-193)
I20260812 06:16:41.957983  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: LogGCOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.059s	user 0.000s	sys 0.058s Metrics: {}
I20260812 06:16:41.958539  2230 maintenance_manager.cc:419] P 3f553c614d1f4fdbbe8dad00da05c8bf: Scheduling MajorDeltaCompactionOp(78119faed6524283b74afb1508ec16d4): perf score=1.000000
W20260812 06:16:42.152045  1951 scanner-internal.cc:458] Time spent opening tablet: real 0.535s	user 0.000s	sys 0.001s
I20260812 06:16:42.154258  1951 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.537s	user 0.000s	sys 0.002s
I20260812 06:16:42.154883  1951 tablet_server.cc:179] TabletServer@127.1.231.193:0 shutting down...
I20260812 06:16:42.942202  2119 maintenance_manager.cc:643] P 3f553c614d1f4fdbbe8dad00da05c8bf: MajorDeltaCompactionOp(78119faed6524283b74afb1508ec16d4) complete. Timing: real 0.983s	user 0.615s	sys 0.367s Metrics: {"cfile_cache_hit":4920,"cfile_cache_hit_bytes":201020640,"cfile_cache_miss":332,"cfile_cache_miss_bytes":16569864,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":22,"delta_iterators_relevant":22,"dirs.queue_time_us":1015,"lbm_read_time_us":10074,"lbm_reads_lt_1ms":368,"lbm_write_time_us":200093,"lbm_writes_lt_1ms":5247,"mutex_wait_us":22,"peak_mem_usage":647164784,"reinsert_count":0,"spinlock_wait_cycles":5120,"thread_start_us":454,"threads_started":7,"update_count":26000,"wal-append.queue_time_us":197}
I20260812 06:16:42.942806  1951 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:42.943207  1951 tablet_replica.cc:333] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf: stopping tablet replica
I20260812 06:16:42.943455  1951 raft_consensus.cc:2243] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:42.943687  1951 raft_consensus.cc:2272] T 78119faed6524283b74afb1508ec16d4 P 3f553c614d1f4fdbbe8dad00da05c8bf [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:42.958607  1951 tablet_server.cc:196] TabletServer@127.1.231.193:0 shutdown complete.
I20260812 06:16:43.755716  1951 master.cc:562] Master@127.1.231.254:42359 shutting down...
I20260812 06:16:43.758929  1951 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 13be22375673457788176ce9a4510c48 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:43.759093  1951 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 13be22375673457788176ce9a4510c48 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:43.759164  1951 tablet_replica.cc:333] T 00000000000000000000000000000000 P 13be22375673457788176ce9a4510c48: stopping tablet replica
I20260812 06:16:43.771327  1951 master.cc:584] Master@127.1.231.254:42359 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (6907 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:16:43.858330  1951 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.1.231.254:42337
I20260812 06:16:43.858732  1951 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:16:43.860651  1951 server_base.cc:1061] running on GCE node
W20260812 06:16:43.860735  2302 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:16:43.860833  2304 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:16:43.860795  2300 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:16:43.861145  1951 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:43.861189  1951 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:16:43.861203  1951 hybrid_clock.cc:648] HybridClock initialized: now 1786515403861204 us; error 0 us; skew 500 ppm
I20260812 06:16:43.861999  1951 webserver.cc:533] Webserver started at http://127.1.231.254:33663/ using document root <none> and password file <none>
I20260812 06:16:43.862130  1951 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:43.862165  1951 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:43.862219  1951 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:43.862555  1951 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/master-0-root/instance:
uuid: "4058fa1bd7eb4956bc2836cd79721390"
format_stamp: "Formatted at 2026-08-12 06:16:43 on dist-test-slave-k5rr"
I20260812 06:16:43.863951  1951 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:16:43.864842  2309 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:16:43.865151  1951 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:16:43.865224  1951 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/master-0-root
uuid: "4058fa1bd7eb4956bc2836cd79721390"
format_stamp: "Formatted at 2026-08-12 06:16:43 on dist-test-slave-k5rr"
I20260812 06:16:43.865288  1951 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-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:16:43.890673  1951 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:43.891004  1951 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:43.895037  1951 rpc_server.cc:307] RPC server started. Bound to: 127.1.231.254:42337
I20260812 06:16:43.905223  2403 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.1.231.254:42337 every 8 connection(s)
I20260812 06:16:43.912573  2405 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:16:43.914482  2405 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4058fa1bd7eb4956bc2836cd79721390: Bootstrap starting.
I20260812 06:16:43.915316  2405 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 4058fa1bd7eb4956bc2836cd79721390: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:43.916322  2405 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4058fa1bd7eb4956bc2836cd79721390: No bootstrap required, opened a new log
I20260812 06:16:43.916702  2405 raft_consensus.cc:359] T 00000000000000000000000000000000 P 4058fa1bd7eb4956bc2836cd79721390 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4058fa1bd7eb4956bc2836cd79721390" member_type: VOTER }
I20260812 06:16:43.916818  2405 raft_consensus.cc:385] T 00000000000000000000000000000000 P 4058fa1bd7eb4956bc2836cd79721390 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:43.916858  2405 raft_consensus.cc:740] T 00000000000000000000000000000000 P 4058fa1bd7eb4956bc2836cd79721390 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 4058fa1bd7eb4956bc2836cd79721390, State: Initialized, Role: FOLLOWER
I20260812 06:16:43.916998  2405 consensus_queue.cc:260] T 00000000000000000000000000000000 P 4058fa1bd7eb4956bc2836cd79721390 [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: "4058fa1bd7eb4956bc2836cd79721390" member_type: VOTER }
I20260812 06:16:43.917104  2405 raft_consensus.cc:399] T 00000000000000000000000000000000 P 4058fa1bd7eb4956bc2836cd79721390 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:43.917142  2405 raft_consensus.cc:493] T 00000000000000000000000000000000 P 4058fa1bd7eb4956bc2836cd79721390 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:43.917192  2405 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 4058fa1bd7eb4956bc2836cd79721390 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:43.917829  2405 raft_consensus.cc:515] T 00000000000000000000000000000000 P 4058fa1bd7eb4956bc2836cd79721390 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4058fa1bd7eb4956bc2836cd79721390" member_type: VOTER }
I20260812 06:16:43.917948  2405 leader_election.cc:304] T 00000000000000000000000000000000 P 4058fa1bd7eb4956bc2836cd79721390 [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: 4058fa1bd7eb4956bc2836cd79721390; no voters: 
I20260812 06:16:43.918119  2405 leader_election.cc:290] T 00000000000000000000000000000000 P 4058fa1bd7eb4956bc2836cd79721390 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:43.918231  2412 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 4058fa1bd7eb4956bc2836cd79721390 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:43.918442  2412 raft_consensus.cc:697] T 00000000000000000000000000000000 P 4058fa1bd7eb4956bc2836cd79721390 [term 1 LEADER]: Becoming Leader. State: Replica: 4058fa1bd7eb4956bc2836cd79721390, State: Running, Role: LEADER
I20260812 06:16:43.918536  2405 sys_catalog.cc:565] T 00000000000000000000000000000000 P 4058fa1bd7eb4956bc2836cd79721390 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:43.918578  2412 consensus_queue.cc:237] T 00000000000000000000000000000000 P 4058fa1bd7eb4956bc2836cd79721390 [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: "4058fa1bd7eb4956bc2836cd79721390" member_type: VOTER }
I20260812 06:16:43.919006  2414 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4058fa1bd7eb4956bc2836cd79721390 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 4058fa1bd7eb4956bc2836cd79721390. Latest consensus state: current_term: 1 leader_uuid: "4058fa1bd7eb4956bc2836cd79721390" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4058fa1bd7eb4956bc2836cd79721390" member_type: VOTER } }
I20260812 06:16:43.918994  2413 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4058fa1bd7eb4956bc2836cd79721390 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "4058fa1bd7eb4956bc2836cd79721390" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4058fa1bd7eb4956bc2836cd79721390" member_type: VOTER } }
I20260812 06:16:43.919102  2414 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4058fa1bd7eb4956bc2836cd79721390 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:43.919114  2413 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4058fa1bd7eb4956bc2836cd79721390 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:43.919406  2418 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:43.920195  2418 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:43.920337  1951 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:43.921947  2418 catalog_manager.cc:1383] Generated new cluster ID: ba579b547bf340a4b6373cfcb774f5e7
I20260812 06:16:43.921995  2418 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:43.929042  2418 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:43.929548  2418 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:43.938900  2418 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 4058fa1bd7eb4956bc2836cd79721390: Generated new TSK 0
I20260812 06:16:43.939040  2418 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:43.952577  1951 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:43.954421  2449 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:16:43.954471  2446 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:16:43.954530  2444 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:16:43.954545  1951 server_base.cc:1061] running on GCE node
I20260812 06:16:43.954900  1951 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:43.954952  1951 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:16:43.954969  1951 hybrid_clock.cc:648] HybridClock initialized: now 1786515403954969 us; error 0 us; skew 500 ppm
I20260812 06:16:43.955781  1951 webserver.cc:533] Webserver started at http://127.1.231.193:38915/ using document root <none> and password file <none>
I20260812 06:16:43.955924  1951 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:43.955971  1951 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:43.956030  1951 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:43.956410  1951 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/instance:
uuid: "933e5b39208e46ca8915e408cde53a9e"
format_stamp: "Formatted at 2026-08-12 06:16:43 on dist-test-slave-k5rr"
I20260812 06:16:43.958030  1951 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:43.959148  2454 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:16:43.959389  1951 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:43.959466  1951 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root
uuid: "933e5b39208e46ca8915e408cde53a9e"
format_stamp: "Formatted at 2026-08-12 06:16:43 on dist-test-slave-k5rr"
I20260812 06:16:43.959537  1951 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-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:16:43.964833  1951 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:43.965194  1951 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:43.965476  1951 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:43.965912  1951 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:43.965950  1951 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:43.965992  1951 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:43.966020  1951 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:43.969947  1951 rpc_server.cc:307] RPC server started. Bound to: 127.1.231.193:42995
I20260812 06:16:43.970001  2556 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.1.231.193:42995 every 8 connection(s)
I20260812 06:16:43.977588  2557 heartbeater.cc:344] Connected to a master server at 127.1.231.254:42337
I20260812 06:16:43.977705  2557 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:43.977941  2557 heartbeater.cc:507] Master 127.1.231.254:42337 requested a full tablet report, sending...
I20260812 06:16:43.978549  2345 ts_manager.cc:194] Registered new tserver with Master: 933e5b39208e46ca8915e408cde53a9e (127.1.231.193:42995)
I20260812 06:16:43.979118  1951 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008767824s
I20260812 06:16:43.979338  2345 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:36540
I20260812 06:16:43.985788  2345 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:36556:
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:16:43.994213  2494 tablet_service.cc:1511] Processing CreateTablet for tablet 8a1abe04563c422799524b01e81ca4a9 (DEFAULT_TABLE table=heavy-update-compaction-test [id=dea0861a8709488fa32ddcfe4e8e3fa6]), partition=
I20260812 06:16:43.994499  2494 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 8a1abe04563c422799524b01e81ca4a9. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:43.996459  2580 tablet_bootstrap.cc:492] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Bootstrap starting.
I20260812 06:16:43.997356  2580 tablet_bootstrap.cc:654] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:43.998350  2580 tablet_bootstrap.cc:492] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: No bootstrap required, opened a new log
I20260812 06:16:43.998425  2580 ts_tablet_manager.cc:1403] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:16:43.998858  2580 raft_consensus.cc:359] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "933e5b39208e46ca8915e408cde53a9e" member_type: VOTER last_known_addr { host: "127.1.231.193" port: 42995 } }
I20260812 06:16:43.998945  2580 raft_consensus.cc:385] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:43.998970  2580 raft_consensus.cc:740] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 933e5b39208e46ca8915e408cde53a9e, State: Initialized, Role: FOLLOWER
I20260812 06:16:43.999102  2580 consensus_queue.cc:260] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e [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: "933e5b39208e46ca8915e408cde53a9e" member_type: VOTER last_known_addr { host: "127.1.231.193" port: 42995 } }
I20260812 06:16:43.999205  2580 raft_consensus.cc:399] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:43.999253  2580 raft_consensus.cc:493] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:43.999296  2580 raft_consensus.cc:3060] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:44.000097  2580 raft_consensus.cc:515] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "933e5b39208e46ca8915e408cde53a9e" member_type: VOTER last_known_addr { host: "127.1.231.193" port: 42995 } }
I20260812 06:16:44.000217  2580 leader_election.cc:304] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e [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: 933e5b39208e46ca8915e408cde53a9e; no voters: 
I20260812 06:16:44.000362  2580 leader_election.cc:290] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:44.000497  2583 raft_consensus.cc:2804] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:44.000706  2557 heartbeater.cc:499] Master 127.1.231.254:42337 was elected leader, sending a full tablet report...
I20260812 06:16:44.000679  2580 ts_tablet_manager.cc:1434] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:44.000696  2583 raft_consensus.cc:697] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e [term 1 LEADER]: Becoming Leader. State: Replica: 933e5b39208e46ca8915e408cde53a9e, State: Running, Role: LEADER
I20260812 06:16:44.000878  2583 consensus_queue.cc:237] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e [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: "933e5b39208e46ca8915e408cde53a9e" member_type: VOTER last_known_addr { host: "127.1.231.193" port: 42995 } }
I20260812 06:16:44.002135  2345 catalog_manager.cc:5719] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e reported cstate change: term changed from 0 to 1, leader changed from <none> to 933e5b39208e46ca8915e408cde53a9e (127.1.231.193). New cstate: current_term: 1 leader_uuid: "933e5b39208e46ca8915e408cde53a9e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "933e5b39208e46ca8915e408cde53a9e" member_type: VOTER last_known_addr { host: "127.1.231.193" port: 42995 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:44.058840  1951 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.049s	user 0.013s	sys 0.008s
I20260812 06:16:44.220746  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushMRSOp(8a1abe04563c422799524b01e81ca4a9): perf score=23.023690
I20260812 06:16:44.369732  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushMRSOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.149s	user 0.121s	sys 0.027s Metrics: {"bytes_written":12307491,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":161,"dirs.run_wall_time_us":736,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39342,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1500}
I20260812 06:16:44.370401  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling LogGCOp(8a1abe04563c422799524b01e81ca4a9): free 20743880 bytes of WAL
I20260812 06:16:44.370617  2460 log_reader.cc:385] T 8a1abe04563c422799524b01e81ca4a9: removed 2 log segments from log reader
I20260812 06:16:44.370666  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000001 (ops 1-6)
I20260812 06:16:44.370697  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000002 (ops 7-11)
I20260812 06:16:44.374305  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: LogGCOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.004s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:16:44.374644  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling UndoDeltaBlockGCOp(8a1abe04563c422799524b01e81ca4a9): 20513813 bytes on disk
I20260812 06:16:44.375037  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: UndoDeltaBlockGCOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:16:44.375437  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=2.188937
I20260812 06:16:44.397548  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.022s	user 0.009s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5994,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:44.398257  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9): perf score=1.000000
I20260812 06:16:44.561221  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.163s	user 0.111s	sys 0.042s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":577,"lbm_read_time_us":10936,"lbm_reads_lt_1ms":460,"lbm_write_time_us":21302,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":314,"threads_started":5,"update_count":2000}
I20260812 06:16:44.561774  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=14.095187
I20260812 06:16:44.607548  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.046s	user 0.024s	sys 0.019s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":19988,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:44.608109  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=2.188937
I20260812 06:16:44.625200  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.017s	user 0.005s	sys 0.012s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6954,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:44.625784  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9): perf score=1.000000
I20260812 06:16:44.773221  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.147s	user 0.114s	sys 0.030s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":3223,"lbm_read_time_us":9987,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28295,"lbm_writes_lt_1ms":543,"mutex_wait_us":2918,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:16:44.773774  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=14.095187
I20260812 06:16:44.817281  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.043s	user 0.022s	sys 0.021s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19469,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:44.817763  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=2.188937
I20260812 06:16:44.828387  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3850,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:44.828816  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9): perf score=1.000000
I20260812 06:16:44.980690  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.152s	user 0.125s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":206,"lbm_read_time_us":9738,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30065,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:16:44.981174  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=11.118625
I20260812 06:16:45.018855  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.038s	user 0.023s	sys 0.013s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16274,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:45.019315  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=2.188937
I20260812 06:16:45.029744  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3889,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:45.030230  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9): perf score=1.000000
I20260812 06:16:45.151091  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.121s	user 0.105s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":109,"lbm_read_time_us":8060,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21720,"lbm_writes_lt_1ms":443,"mutex_wait_us":25,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:16:45.151715  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=10.126437
I20260812 06:16:45.198513  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.047s	user 0.026s	sys 0.019s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15180,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:45.199117  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=2.188937
I20260812 06:16:45.214038  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.015s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5723,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:45.214524  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9): perf score=1.000000
I20260812 06:16:45.358673  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.144s	user 0.092s	sys 0.049s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":159,"lbm_read_time_us":11233,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22736,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:45.359225  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=10.126437
I20260812 06:16:45.403971  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.045s	user 0.025s	sys 0.004s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13807,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:45.404469  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=2.188937
I20260812 06:16:45.416280  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4219,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:45.416944  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9): perf score=1.000000
I20260812 06:16:45.548769  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.132s	user 0.102s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":356,"lbm_read_time_us":9790,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25547,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4608,"update_count":2000}
I20260812 06:16:45.549405  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=10.126437
I20260812 06:16:45.599907  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.050s	user 0.030s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":22494,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:45.600483  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=2.188937
I20260812 06:16:45.617391  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.017s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6021,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:45.617826  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushMRSOp(8a1abe04563c422799524b01e81ca4a9): perf score=1.000000
I20260812 06:16:45.648281  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushMRSOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.030s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":50,"dirs.run_cpu_time_us":245,"dirs.run_wall_time_us":1349,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1451,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:16:45.649143  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling LogGCOp(8a1abe04563c422799524b01e81ca4a9): free 124257238 bytes of WAL
I20260812 06:16:45.649480  2460 log_reader.cc:385] T 8a1abe04563c422799524b01e81ca4a9: removed 12 log segments from log reader
I20260812 06:16:45.649533  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000003 (ops 12-16)
I20260812 06:16:45.649561  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000004 (ops 17-21)
I20260812 06:16:45.649577  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000005 (ops 22-26)
I20260812 06:16:45.649595  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000006 (ops 27-31)
I20260812 06:16:45.649626  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000007 (ops 32-36)
I20260812 06:16:45.649658  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000008 (ops 37-41)
I20260812 06:16:45.649714  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000009 (ops 42-46)
I20260812 06:16:45.649747  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000010 (ops 47-51)
I20260812 06:16:45.649821  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000011 (ops 52-56)
I20260812 06:16:45.649860  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000012 (ops 57-61)
I20260812 06:16:45.649883  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000013 (ops 62-66)
I20260812 06:16:45.649950  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000014 (ops 67-70)
I20260812 06:16:45.672956  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: LogGCOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.024s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:16:45.673614  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=5.165500
I20260812 06:16:45.688249  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":6400018,"delete_count":0,"lbm_write_time_us":5720,"lbm_writes_lt_1ms":159,"reinsert_count":0,"update_count":780}
I20260812 06:16:45.688673  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling LogGCOp(8a1abe04563c422799524b01e81ca4a9): free 8767118 bytes of WAL
I20260812 06:16:45.688867  2460 log_reader.cc:385] T 8a1abe04563c422799524b01e81ca4a9: removed 1 log segments from log reader
I20260812 06:16:45.688911  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000015 (ops 71-75)
I20260812 06:16:45.690570  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: LogGCOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:16:45.690893  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling UndoDeltaBlockGCOp(8a1abe04563c422799524b01e81ca4a9): 486 bytes on disk
I20260812 06:16:45.691282  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: UndoDeltaBlockGCOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:16:45.691735  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=1.000000
I20260812 06:16:45.702541  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.011s	user 0.007s	sys 0.001s Metrics: {"bytes_written":1805252,"delete_count":0,"lbm_write_time_us":2704,"lbm_writes_lt_1ms":47,"reinsert_count":0,"update_count":220}
I20260812 06:16:45.703068  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9): perf score=1.000000
I20260812 06:16:45.860493  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.157s	user 0.137s	sys 0.020s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918281,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":179,"lbm_read_time_us":11965,"lbm_reads_lt_1ms":670,"lbm_write_time_us":29323,"lbm_writes_lt_1ms":643,"mutex_wait_us":34,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9216,"thread_start_us":73,"threads_started":1,"update_count":3000}
I20260812 06:16:45.861106  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=14.095187
I20260812 06:16:45.910225  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.049s	user 0.019s	sys 0.020s Metrics: {"bytes_written":16409881,"delete_count":0,"lbm_write_time_us":17667,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:45.910647  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=2.188937
I20260812 06:16:45.920432  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3741,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:45.920866  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9): perf score=1.000000
I20260812 06:16:46.053638  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.133s	user 0.132s	sys 0.000s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815662,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":263,"lbm_read_time_us":10161,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25882,"lbm_writes_lt_1ms":543,"mutex_wait_us":33,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:16:46.054198  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=10.126437
I20260812 06:16:46.086280  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.032s	user 0.027s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13388,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:46.086854  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=2.188937
I20260812 06:16:46.104279  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.017s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6268,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:46.104839  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9): perf score=1.000000
I20260812 06:16:46.245184  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.140s	user 0.107s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":136,"lbm_read_time_us":8735,"lbm_reads_lt_1ms":464,"lbm_write_time_us":28058,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:46.245975  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=10.126437
I20260812 06:16:46.280653  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.034s	user 0.013s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":12600,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:46.281134  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=2.188937
I20260812 06:16:46.296041  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5399,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:46.296646  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9): perf score=1.000000
I20260812 06:16:46.417366  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.121s	user 0.109s	sys 0.011s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":127,"lbm_read_time_us":8226,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22879,"lbm_writes_lt_1ms":443,"mutex_wait_us":54,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":65920,"update_count":2000}
I20260812 06:16:46.417893  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=10.126437
I20260812 06:16:46.470753  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.053s	user 0.025s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14496,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:46.471318  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=2.188937
I20260812 06:16:46.486441  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5648,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:46.486965  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9): perf score=1.000000
I20260812 06:16:46.633545  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.146s	user 0.111s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":51,"lbm_read_time_us":10786,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22142,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12672,"update_count":2000}
I20260812 06:16:46.634140  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=10.126437
I20260812 06:16:46.667312  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.033s	user 0.020s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13372,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":1500}
I20260812 06:16:46.667809  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=2.188937
I20260812 06:16:46.682777  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.015s	user 0.013s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5459,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:46.683303  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9): perf score=1.000000
I20260812 06:16:46.799724  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.116s	user 0.096s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":278,"lbm_read_time_us":7824,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22496,"lbm_writes_lt_1ms":443,"mutex_wait_us":52,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":2000}
I20260812 06:16:46.800216  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=10.126437
I20260812 06:16:46.836035  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.036s	user 0.012s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13064,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:46.836585  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=2.188937
I20260812 06:16:46.851436  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5405,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:46.851959  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9): perf score=1.000000
I20260812 06:16:46.980585  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.128s	user 0.108s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1040,"lbm_read_time_us":8613,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24804,"lbm_writes_lt_1ms":443,"mutex_wait_us":277,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2000}
I20260812 06:16:46.981127  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=10.126437
I20260812 06:16:47.025519  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.044s	user 0.020s	sys 0.019s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13450,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:47.026088  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=2.188937
I20260812 06:16:47.041641  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.015s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5944,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:47.042148  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushMRSOp(8a1abe04563c422799524b01e81ca4a9): perf score=1.000000
I20260812 06:16:47.078732  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushMRSOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.036s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":177,"dirs.run_wall_time_us":1168,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1346,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:16:47.079501  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling LogGCOp(8a1abe04563c422799524b01e81ca4a9): free 121006471 bytes of WAL
I20260812 06:16:47.079743  2460 log_reader.cc:385] T 8a1abe04563c422799524b01e81ca4a9: removed 12 log segments from log reader
I20260812 06:16:47.079805  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000016 (ops 76-80)
I20260812 06:16:47.079852  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000017 (ops 81-85)
I20260812 06:16:47.079887  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000018 (ops 86-90)
I20260812 06:16:47.079916  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000019 (ops 91-94)
I20260812 06:16:47.079944  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000020 (ops 95-99)
I20260812 06:16:47.079974  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000021 (ops 100-104)
I20260812 06:16:47.080006  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000022 (ops 105-109)
I20260812 06:16:47.080039  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000023 (ops 110-114)
I20260812 06:16:47.080068  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000024 (ops 115-119)
I20260812 06:16:47.080096  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000025 (ops 120-124)
I20260812 06:16:47.080123  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000026 (ops 125-129)
I20260812 06:16:47.080145  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000027 (ops 130-134)
I20260812 06:16:47.106787  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: LogGCOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.027s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:16:47.107158  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=3.181125
I20260812 06:16:47.123785  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.016s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4020,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:47.124259  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling UndoDeltaBlockGCOp(8a1abe04563c422799524b01e81ca4a9): 472 bytes on disk
I20260812 06:16:47.124686  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: UndoDeltaBlockGCOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:16:47.125524  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=2.188937
I20260812 06:16:47.134583  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.009s	user 0.002s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3237,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:47.135151  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9): perf score=1.000000
I20260812 06:16:47.333636  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.198s	user 0.128s	sys 0.068s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918325,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2622,"lbm_read_time_us":13036,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33558,"lbm_writes_lt_1ms":643,"mutex_wait_us":1832,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3456,"thread_start_us":86,"threads_started":1,"update_count":3000}
I20260812 06:16:47.334998  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=14.095187
I20260812 06:16:47.388232  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.053s	user 0.028s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20873,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:47.388820  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=2.188937
I20260812 06:16:47.404413  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5801,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:47.405081  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9): perf score=1.000000
I20260812 06:16:47.581727  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.176s	user 0.133s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":361,"lbm_read_time_us":10688,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28711,"lbm_writes_lt_1ms":543,"mutex_wait_us":94,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11520,"update_count":2500}
I20260812 06:16:47.582304  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=14.095187
I20260812 06:16:47.639886  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.057s	user 0.025s	sys 0.014s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":18382,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:47.640484  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=2.188937
I20260812 06:16:47.655973  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6054,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:47.656590  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9): perf score=1.000000
I20260812 06:16:47.833163  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.176s	user 0.106s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":699,"lbm_read_time_us":13079,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29117,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":26112,"update_count":2500}
I20260812 06:16:47.833784  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=14.095187
I20260812 06:16:47.883791  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.050s	user 0.028s	sys 0.018s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":17096,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:47.884375  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=2.188937
I20260812 06:16:47.899044  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5576,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:47.899538  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9): perf score=1.000000
I20260812 06:16:48.085424  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.186s	user 0.108s	sys 0.076s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1252,"lbm_read_time_us":13428,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32997,"lbm_writes_lt_1ms":543,"mutex_wait_us":558,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13312,"update_count":2500}
I20260812 06:16:48.085956  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=14.095187
I20260812 06:16:48.139055  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.053s	user 0.031s	sys 0.017s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22369,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:48.139607  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=2.188937
I20260812 06:16:48.158591  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.019s	user 0.006s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4050,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:48.159122  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9): perf score=1.000000
I20260812 06:16:48.355928  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.197s	user 0.121s	sys 0.069s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":3546,"lbm_read_time_us":12462,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33339,"lbm_writes_lt_1ms":543,"mutex_wait_us":3202,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":2500}
I20260812 06:16:48.356840  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=14.095187
I20260812 06:16:48.407210  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.050s	user 0.032s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22400,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:48.407677  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=2.188937
I20260812 06:16:48.418290  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3621,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:48.418733  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9): perf score=1.000000
I20260812 06:16:48.591387  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.172s	user 0.111s	sys 0.050s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":900,"lbm_read_time_us":12056,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25066,"lbm_writes_lt_1ms":543,"mutex_wait_us":328,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2500}
I20260812 06:16:48.591997  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=14.095187
I20260812 06:16:48.649597  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.057s	user 0.034s	sys 0.023s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":25241,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:16:48.650075  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=2.188937
I20260812 06:16:48.661698  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4373,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:48.662168  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushMRSOp(8a1abe04563c422799524b01e81ca4a9): perf score=1.000000
I20260812 06:16:48.693691  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushMRSOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.031s	user 0.027s	sys 0.004s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":216,"dirs.run_wall_time_us":1115,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1440,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:16:48.694701  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling LogGCOp(8a1abe04563c422799524b01e81ca4a9): free 133024646 bytes of WAL
I20260812 06:16:48.694975  2460 log_reader.cc:385] T 8a1abe04563c422799524b01e81ca4a9: removed 13 log segments from log reader
I20260812 06:16:48.695026  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000028 (ops 135-139)
I20260812 06:16:48.695065  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000029 (ops 140-144)
I20260812 06:16:48.695098  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000030 (ops 145-149)
I20260812 06:16:48.695130  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000031 (ops 150-154)
I20260812 06:16:48.695161  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000032 (ops 155-159)
I20260812 06:16:48.695191  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000033 (ops 160-164)
I20260812 06:16:48.695221  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000034 (ops 165-169)
I20260812 06:16:48.695261  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000035 (ops 170-174)
I20260812 06:16:48.695291  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000036 (ops 175-178)
I20260812 06:16:48.695322  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000037 (ops 179-183)
I20260812 06:16:48.695353  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000038 (ops 184-188)
I20260812 06:16:48.695381  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000039 (ops 189-193)
I20260812 06:16:48.695411  2460 log.cc:1079] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: Deleting log segment in path: /tmp/dist-test-tasknUT4GL/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515396927000-1951-0/minicluster-data/ts-0-root/wals/8a1abe04563c422799524b01e81ca4a9/wal-000000040 (ops 194-198)
I20260812 06:16:48.721907  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: LogGCOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:16:48.722333  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling UndoDeltaBlockGCOp(8a1abe04563c422799524b01e81ca4a9): 493 bytes on disk
I20260812 06:16:48.722872  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: UndoDeltaBlockGCOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:16:48.723517  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=3.181125
I20260812 06:16:48.736979  1951 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.678s	user 1.731s	sys 0.133s
I20260812 06:16:48.738996  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.015s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":3928,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:48.739434  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9): perf score=2.188937
I20260812 06:16:48.748358  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: FlushDeltaMemStoresOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.009s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3550,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:48.748741  2558 maintenance_manager.cc:419] P 933e5b39208e46ca8915e408cde53a9e: Scheduling MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9): perf score=1.000000
I20260812 06:16:48.820978  1951 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.084s	user 0.000s	sys 0.000s
I20260812 06:16:48.821610  1951 tablet_server.cc:179] TabletServer@127.1.231.193:0 shutting down...
I20260812 06:16:48.912106  2460 maintenance_manager.cc:643] P 933e5b39208e46ca8915e408cde53a9e: MajorDeltaCompactionOp(8a1abe04563c422799524b01e81ca4a9) complete. Timing: real 0.163s	user 0.131s	sys 0.032s Metrics: {"cfile_cache_hit":221,"cfile_cache_hit_bytes":8948762,"cfile_cache_miss":513,"cfile_cache_miss_bytes":24071974,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":843,"lbm_read_time_us":10434,"lbm_reads_lt_1ms":545,"lbm_write_time_us":31061,"lbm_writes_lt_1ms":743,"mutex_wait_us":57,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":5120,"thread_start_us":303,"threads_started":1,"update_count":3500}
I20260812 06:16:48.912883  1951 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:48.913287  1951 tablet_replica.cc:333] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e: stopping tablet replica
I20260812 06:16:48.913432  1951 raft_consensus.cc:2243] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:48.913594  1951 raft_consensus.cc:2272] T 8a1abe04563c422799524b01e81ca4a9 P 933e5b39208e46ca8915e408cde53a9e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:48.927309  1951 tablet_server.cc:196] TabletServer@127.1.231.193:0 shutdown complete.
I20260812 06:16:48.969578  1951 master.cc:562] Master@127.1.231.254:42337 shutting down...
I20260812 06:16:48.972790  1951 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 4058fa1bd7eb4956bc2836cd79721390 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:48.972965  1951 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 4058fa1bd7eb4956bc2836cd79721390 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:48.973052  1951 tablet_replica.cc:333] T 00000000000000000000000000000000 P 4058fa1bd7eb4956bc2836cd79721390: stopping tablet replica
I20260812 06:16:48.985464  1951 master.cc:584] Master@127.1.231.254:42337 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5213 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (12122 ms total)

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