[==========] 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:17:34.356941  9968 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.9.188.62:37913
I20260812 06:17:34.357911  9968 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:17:34.358490  9968 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:17:34.364607  9968 server_base.cc:1061] running on GCE node
W20260812 06:17:34.364629  9977 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:17:34.364612  9979 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:17:34.364924  9976 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:17:34.365558  9968 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:34.365665  9968 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:17:34.365710  9968 hybrid_clock.cc:648] HybridClock initialized: now 1786515454365708 us; error 0 us; skew 500 ppm
I20260812 06:17:34.367451  9968 webserver.cc:533] Webserver started at http://127.9.188.62:40443/ using document root <none> and password file <none>
I20260812 06:17:34.367966  9968 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:34.368026  9968 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:34.368237  9968 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:34.369838  9968 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/master-0-root/instance:
uuid: "cab1ab86f7dd44919bf14eb732816f64"
format_stamp: "Formatted at 2026-08-12 06:17:34 on dist-test-slave-7lbf"
I20260812 06:17:34.373088  9968 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:17:34.375137  9991 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:17:34.376125  9968 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.000s	sys 0.001s
I20260812 06:17:34.376223  9968 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/master-0-root
uuid: "cab1ab86f7dd44919bf14eb732816f64"
format_stamp: "Formatted at 2026-08-12 06:17:34 on dist-test-slave-7lbf"
I20260812 06:17:34.376317  9968 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-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:17:34.405308  9968 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:34.406014  9968 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:17:34.406180  9968 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:34.413506 10082 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.9.188.62:37913 every 8 connection(s)
I20260812 06:17:34.413532  9968 rpc_server.cc:307] RPC server started. Bound to: 127.9.188.62:37913
I20260812 06:17:34.415781 10083 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:17:34.421248 10083 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P cab1ab86f7dd44919bf14eb732816f64: Bootstrap starting.
I20260812 06:17:34.423616 10083 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P cab1ab86f7dd44919bf14eb732816f64: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:34.424497 10083 log.cc:826] T 00000000000000000000000000000000 P cab1ab86f7dd44919bf14eb732816f64: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:34.426174 10083 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P cab1ab86f7dd44919bf14eb732816f64: No bootstrap required, opened a new log
I20260812 06:17:34.428956 10083 raft_consensus.cc:359] T 00000000000000000000000000000000 P cab1ab86f7dd44919bf14eb732816f64 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cab1ab86f7dd44919bf14eb732816f64" member_type: VOTER }
I20260812 06:17:34.429129 10083 raft_consensus.cc:385] T 00000000000000000000000000000000 P cab1ab86f7dd44919bf14eb732816f64 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:34.429177 10083 raft_consensus.cc:740] T 00000000000000000000000000000000 P cab1ab86f7dd44919bf14eb732816f64 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: cab1ab86f7dd44919bf14eb732816f64, State: Initialized, Role: FOLLOWER
I20260812 06:17:34.429803 10083 consensus_queue.cc:260] T 00000000000000000000000000000000 P cab1ab86f7dd44919bf14eb732816f64 [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: "cab1ab86f7dd44919bf14eb732816f64" member_type: VOTER }
I20260812 06:17:34.429960 10083 raft_consensus.cc:399] T 00000000000000000000000000000000 P cab1ab86f7dd44919bf14eb732816f64 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:34.430007 10083 raft_consensus.cc:493] T 00000000000000000000000000000000 P cab1ab86f7dd44919bf14eb732816f64 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:34.430095 10083 raft_consensus.cc:3060] T 00000000000000000000000000000000 P cab1ab86f7dd44919bf14eb732816f64 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:34.430856 10083 raft_consensus.cc:515] T 00000000000000000000000000000000 P cab1ab86f7dd44919bf14eb732816f64 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cab1ab86f7dd44919bf14eb732816f64" member_type: VOTER }
I20260812 06:17:34.431262 10083 leader_election.cc:304] T 00000000000000000000000000000000 P cab1ab86f7dd44919bf14eb732816f64 [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: cab1ab86f7dd44919bf14eb732816f64; no voters: 
I20260812 06:17:34.431528 10083 leader_election.cc:290] T 00000000000000000000000000000000 P cab1ab86f7dd44919bf14eb732816f64 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:34.431661 10089 raft_consensus.cc:2804] T 00000000000000000000000000000000 P cab1ab86f7dd44919bf14eb732816f64 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:34.431887 10089 raft_consensus.cc:697] T 00000000000000000000000000000000 P cab1ab86f7dd44919bf14eb732816f64 [term 1 LEADER]: Becoming Leader. State: Replica: cab1ab86f7dd44919bf14eb732816f64, State: Running, Role: LEADER
I20260812 06:17:34.432286 10089 consensus_queue.cc:237] T 00000000000000000000000000000000 P cab1ab86f7dd44919bf14eb732816f64 [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: "cab1ab86f7dd44919bf14eb732816f64" member_type: VOTER }
I20260812 06:17:34.432507 10083 sys_catalog.cc:565] T 00000000000000000000000000000000 P cab1ab86f7dd44919bf14eb732816f64 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:34.434182 10090 sys_catalog.cc:455] T 00000000000000000000000000000000 P cab1ab86f7dd44919bf14eb732816f64 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "cab1ab86f7dd44919bf14eb732816f64" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cab1ab86f7dd44919bf14eb732816f64" member_type: VOTER } }
I20260812 06:17:34.434222 10092 sys_catalog.cc:455] T 00000000000000000000000000000000 P cab1ab86f7dd44919bf14eb732816f64 [sys.catalog]: SysCatalogTable state changed. Reason: New leader cab1ab86f7dd44919bf14eb732816f64. Latest consensus state: current_term: 1 leader_uuid: "cab1ab86f7dd44919bf14eb732816f64" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cab1ab86f7dd44919bf14eb732816f64" member_type: VOTER } }
I20260812 06:17:34.434303 10090 sys_catalog.cc:458] T 00000000000000000000000000000000 P cab1ab86f7dd44919bf14eb732816f64 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:34.434315 10092 sys_catalog.cc:458] T 00000000000000000000000000000000 P cab1ab86f7dd44919bf14eb732816f64 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:34.434823  9968 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:34.434829 10121 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:34.437117 10121 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:34.441341 10121 catalog_manager.cc:1383] Generated new cluster ID: 7cda96550bda49afa7fecf780f3d382e
I20260812 06:17:34.441401 10121 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:34.449621 10121 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:34.450721 10121 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:34.478560 10121 catalog_manager.cc:6092] T 00000000000000000000000000000000 P cab1ab86f7dd44919bf14eb732816f64: Generated new TSK 0
I20260812 06:17:34.479357 10121 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:34.499400  9968 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:34.502027 10139 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:34.502170 10146 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:17:34.502264 10142 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:17:34.502449  9968 server_base.cc:1061] running on GCE node
I20260812 06:17:34.502653  9968 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:34.502692  9968 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:17:34.502712  9968 hybrid_clock.cc:648] HybridClock initialized: now 1786515454502712 us; error 0 us; skew 500 ppm
I20260812 06:17:34.503545  9968 webserver.cc:533] Webserver started at http://127.9.188.1:35633/ using document root <none> and password file <none>
I20260812 06:17:34.503700  9968 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:34.503744  9968 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:34.503818  9968 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:34.504170  9968 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/instance:
uuid: "624f4101226746eead34f8f30f0db2dc"
format_stamp: "Formatted at 2026-08-12 06:17:34 on dist-test-slave-7lbf"
I20260812 06:17:34.505705  9968 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:34.506611 10153 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:17:34.506898  9968 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:34.506964  9968 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root
uuid: "624f4101226746eead34f8f30f0db2dc"
format_stamp: "Formatted at 2026-08-12 06:17:34 on dist-test-slave-7lbf"
I20260812 06:17:34.507030  9968 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-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:17:34.535200  9968 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:34.535684  9968 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:34.536177  9968 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:34.537030  9968 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:34.537082  9968 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:34.537138  9968 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:34.537178  9968 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:34.543300  9968 rpc_server.cc:307] RPC server started. Bound to: 127.9.188.1:37879
I20260812 06:17:34.543340 10259 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.9.188.1:37879 every 8 connection(s)
I20260812 06:17:34.555315 10262 heartbeater.cc:344] Connected to a master server at 127.9.188.62:37913
I20260812 06:17:34.555558 10262 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:34.556025 10262 heartbeater.cc:507] Master 127.9.188.62:37913 requested a full tablet report, sending...
I20260812 06:17:34.557467 10025 ts_manager.cc:194] Registered new tserver with Master: 624f4101226746eead34f8f30f0db2dc (127.9.188.1:37879)
I20260812 06:17:34.558378  9968 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.014474767s
I20260812 06:17:34.558787 10025 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:58404
I20260812 06:17:34.567340 10025 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:58406:
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:17:34.580832 10194 tablet_service.cc:1511] Processing CreateTablet for tablet 02df376b87404639b8fd63a7cb2c6ef7 (DEFAULT_TABLE table=heavy-update-compaction-test [id=525d02aa67674fae82402eee11cea333]), partition=
I20260812 06:17:34.581283 10194 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 02df376b87404639b8fd63a7cb2c6ef7. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:34.583530 10284 tablet_bootstrap.cc:492] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Bootstrap starting.
I20260812 06:17:34.584991 10284 tablet_bootstrap.cc:654] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:34.586359 10284 tablet_bootstrap.cc:492] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: No bootstrap required, opened a new log
I20260812 06:17:34.586485 10284 ts_tablet_manager.cc:1403] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:17:34.587019 10284 raft_consensus.cc:359] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "624f4101226746eead34f8f30f0db2dc" member_type: VOTER last_known_addr { host: "127.9.188.1" port: 37879 } }
I20260812 06:17:34.587145 10284 raft_consensus.cc:385] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:34.587186 10284 raft_consensus.cc:740] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 624f4101226746eead34f8f30f0db2dc, State: Initialized, Role: FOLLOWER
I20260812 06:17:34.587316 10284 consensus_queue.cc:260] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc [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: "624f4101226746eead34f8f30f0db2dc" member_type: VOTER last_known_addr { host: "127.9.188.1" port: 37879 } }
I20260812 06:17:34.587416 10284 raft_consensus.cc:399] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:34.587458 10284 raft_consensus.cc:493] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:34.587507 10284 raft_consensus.cc:3060] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:34.588444 10284 raft_consensus.cc:515] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "624f4101226746eead34f8f30f0db2dc" member_type: VOTER last_known_addr { host: "127.9.188.1" port: 37879 } }
I20260812 06:17:34.588593 10284 leader_election.cc:304] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc [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: 624f4101226746eead34f8f30f0db2dc; no voters: 
I20260812 06:17:34.588804 10284 leader_election.cc:290] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:34.588923 10291 raft_consensus.cc:2804] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:34.589154 10284 ts_tablet_manager.cc:1434] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:17:34.589160 10291 raft_consensus.cc:697] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc [term 1 LEADER]: Becoming Leader. State: Replica: 624f4101226746eead34f8f30f0db2dc, State: Running, Role: LEADER
I20260812 06:17:34.589326 10291 consensus_queue.cc:237] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc [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: "624f4101226746eead34f8f30f0db2dc" member_type: VOTER last_known_addr { host: "127.9.188.1" port: 37879 } }
I20260812 06:17:34.589462 10262 heartbeater.cc:499] Master 127.9.188.62:37913 was elected leader, sending a full tablet report...
I20260812 06:17:34.591815 10025 catalog_manager.cc:5719] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc reported cstate change: term changed from 0 to 1, leader changed from <none> to 624f4101226746eead34f8f30f0db2dc (127.9.188.1). New cstate: current_term: 1 leader_uuid: "624f4101226746eead34f8f30f0db2dc" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "624f4101226746eead34f8f30f0db2dc" member_type: VOTER last_known_addr { host: "127.9.188.1" port: 37879 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:34.651857  9968 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.051s	user 0.016s	sys 0.008s
I20260812 06:17:34.794433 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushMRSOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=19.054940
I20260812 06:17:34.962275 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushMRSOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.168s	user 0.099s	sys 0.064s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":253,"delete_count":0,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":181,"dirs.run_wall_time_us":2532,"drs_written":1,"lbm_read_time_us":107,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41974,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":756,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":127,"threads_started":1,"update_count":1500}
I20260812 06:17:34.963810 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling LogGCOp(02df376b87404639b8fd63a7cb2c6ef7): free 20743880 bytes of WAL
I20260812 06:17:34.964178 10160 log_reader.cc:385] T 02df376b87404639b8fd63a7cb2c6ef7: removed 2 log segments from log reader
I20260812 06:17:34.964264 10160 log.cc:1079] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/02df376b87404639b8fd63a7cb2c6ef7/wal-000000001 (ops 1-6)
I20260812 06:17:34.964329 10160 log.cc:1079] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/02df376b87404639b8fd63a7cb2c6ef7/wal-000000002 (ops 7-11)
I20260812 06:17:34.970055 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: LogGCOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.006s	user 0.000s	sys 0.006s Metrics: {}
I20260812 06:17:34.970412 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=3.181125
I20260812 06:17:35.002214 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.032s	user 0.008s	sys 0.011s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4210,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:35.002687 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling UndoDeltaBlockGCOp(02df376b87404639b8fd63a7cb2c6ef7): 16411396 bytes on disk
I20260812 06:17:35.003330 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: UndoDeltaBlockGCOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4}
I20260812 06:17:35.003774 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=2.188937
I20260812 06:17:35.017669 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.014s	user 0.013s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5198,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:35.018220 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=1.000000
I20260812 06:17:35.181286 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.163s	user 0.110s	sys 0.053s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774798,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":800,"lbm_read_time_us":11807,"lbm_reads_lt_1ms":569,"lbm_write_time_us":26408,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"thread_start_us":306,"threads_started":5,"update_count":2500}
I20260812 06:17:35.181871 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=10.126437
I20260812 06:17:35.224299 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.042s	user 0.018s	sys 0.015s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15645,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:35.224754 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=2.188937
I20260812 06:17:35.235227 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3839,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.235845 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=1.000000
I20260812 06:17:35.376531 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.140s	user 0.112s	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":518,"lbm_read_time_us":8070,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27878,"lbm_writes_lt_1ms":443,"mutex_wait_us":290,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2000}
I20260812 06:17:35.377256 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=10.126437
I20260812 06:17:35.408646 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.031s	user 0.021s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13331,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:35.409099 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=1.000000
I20260812 06:17:35.512499 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.103s	user 0.079s	sys 0.024s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":399,"lbm_read_time_us":6007,"lbm_reads_lt_1ms":363,"lbm_write_time_us":17655,"lbm_writes_lt_1ms":343,"mutex_wait_us":68,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":1500}
I20260812 06:17:35.513314 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=10.126437
I20260812 06:17:35.550534 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.037s	user 0.024s	sys 0.011s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":17463,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:17:35.551131 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=1.000000
I20260812 06:17:35.662557 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.111s	user 0.079s	sys 0.032s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569748,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":181,"lbm_read_time_us":7696,"lbm_reads_lt_1ms":367,"lbm_write_time_us":18254,"lbm_writes_lt_1ms":343,"mutex_wait_us":31,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":92160,"update_count":1500}
I20260812 06:17:35.663131 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=10.126437
I20260812 06:17:35.702947 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.040s	user 0.013s	sys 0.023s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16550,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:35.703441 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=2.188937
I20260812 06:17:35.718910 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5697,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.719466 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=1.000000
I20260812 06:17:35.844307 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.125s	user 0.095s	sys 0.027s 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":284,"lbm_read_time_us":8476,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23694,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:35.844772 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=10.126437
I20260812 06:17:35.884099 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.039s	user 0.016s	sys 0.016s Metrics: {"bytes_written":12307494,"delete_count":0,"lbm_write_time_us":16031,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:35.884657 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=2.188937
I20260812 06:17:35.895051 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3920,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.895601 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=1.000000
I20260812 06:17:36.017067 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.121s	user 0.097s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":252,"lbm_read_time_us":9481,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23008,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2000}
I20260812 06:17:36.017843 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=10.126437
I20260812 06:17:36.067349 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.049s	user 0.009s	sys 0.036s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15238,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:36.067970 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=2.188937
I20260812 06:17:36.078140 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3813,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.078599 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=1.000000
I20260812 06:17:36.215169 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.136s	user 0.077s	sys 0.056s 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":260,"lbm_read_time_us":9737,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20106,"lbm_writes_lt_1ms":443,"mutex_wait_us":46,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":2000}
I20260812 06:17:36.215754 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=10.126437
I20260812 06:17:36.259146 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.043s	user 0.014s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13587,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:36.259660 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=2.188937
I20260812 06:17:36.271191 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4209,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.271644 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushMRSOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=1.000000
I20260812 06:17:36.302260 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushMRSOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.030s	user 0.025s	sys 0.005s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":49,"dirs.run_cpu_time_us":224,"dirs.run_wall_time_us":1502,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1433,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:36.303007 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling LogGCOp(02df376b87404639b8fd63a7cb2c6ef7): free 124257240 bytes of WAL
I20260812 06:17:36.303216 10160 log_reader.cc:385] T 02df376b87404639b8fd63a7cb2c6ef7: removed 12 log segments from log reader
I20260812 06:17:36.303260 10160 log.cc:1079] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/02df376b87404639b8fd63a7cb2c6ef7/wal-000000003 (ops 12-16)
I20260812 06:17:36.303288 10160 log.cc:1079] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/02df376b87404639b8fd63a7cb2c6ef7/wal-000000004 (ops 17-21)
I20260812 06:17:36.303321 10160 log.cc:1079] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/02df376b87404639b8fd63a7cb2c6ef7/wal-000000005 (ops 22-26)
I20260812 06:17:36.303356 10160 log.cc:1079] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/02df376b87404639b8fd63a7cb2c6ef7/wal-000000006 (ops 27-31)
I20260812 06:17:36.303388 10160 log.cc:1079] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/02df376b87404639b8fd63a7cb2c6ef7/wal-000000007 (ops 32-36)
I20260812 06:17:36.303419 10160 log.cc:1079] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/02df376b87404639b8fd63a7cb2c6ef7/wal-000000008 (ops 37-41)
I20260812 06:17:36.303449 10160 log.cc:1079] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/02df376b87404639b8fd63a7cb2c6ef7/wal-000000009 (ops 42-46)
I20260812 06:17:36.303480 10160 log.cc:1079] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/02df376b87404639b8fd63a7cb2c6ef7/wal-000000010 (ops 47-51)
I20260812 06:17:36.303511 10160 log.cc:1079] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/02df376b87404639b8fd63a7cb2c6ef7/wal-000000011 (ops 52-56)
I20260812 06:17:36.303541 10160 log.cc:1079] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/02df376b87404639b8fd63a7cb2c6ef7/wal-000000012 (ops 57-61)
I20260812 06:17:36.303573 10160 log.cc:1079] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/02df376b87404639b8fd63a7cb2c6ef7/wal-000000013 (ops 62-66)
I20260812 06:17:36.303603 10160 log.cc:1079] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/02df376b87404639b8fd63a7cb2c6ef7/wal-000000014 (ops 67-70)
I20260812 06:17:36.328931 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: LogGCOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.026s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:17:36.329413 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=3.181125
I20260812 06:17:36.353335 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.024s	user 0.016s	sys 0.004s Metrics: {"bytes_written":5046217,"delete_count":0,"lbm_write_time_us":6558,"lbm_writes_lt_1ms":126,"reinsert_count":0,"update_count":615}
I20260812 06:17:36.353917 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=1.196750
I20260812 06:17:36.362396 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.008s	user 0.002s	sys 0.005s Metrics: {"bytes_written":3159080,"delete_count":0,"lbm_write_time_us":3023,"lbm_writes_lt_1ms":80,"reinsert_count":0,"update_count":385}
I20260812 06:17:36.362879 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=1.000000
I20260812 06:17:36.562039 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.199s	user 0.144s	sys 0.053s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877318,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":509,"lbm_read_time_us":15762,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34106,"lbm_writes_lt_1ms":643,"mutex_wait_us":311,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6528,"thread_start_us":74,"threads_started":1,"update_count":3000}
I20260812 06:17:36.563828 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=14.095187
I20260812 06:17:36.618743 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.055s	user 0.019s	sys 0.035s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19824,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:36.619237 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling UndoDeltaBlockGCOp(02df376b87404639b8fd63a7cb2c6ef7): 481 bytes on disk
I20260812 06:17:36.619685 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: UndoDeltaBlockGCOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:17:36.620188 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=2.188937
I20260812 06:17:36.630429 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3807,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.630909 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=1.000000
I20260812 06:17:36.803433 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.172s	user 0.121s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":221,"lbm_read_time_us":12090,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28737,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:36.806857 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=11.118625
I20260812 06:17:36.861846 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.054s	user 0.034s	sys 0.008s Metrics: {"bytes_written":13374126,"delete_count":0,"lbm_write_time_us":20005,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":327,"reinsert_count":0,"update_count":1630}
I20260812 06:17:36.862349 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=5.165500
I20260812 06:17:36.886433 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.024s	user 0.012s	sys 0.011s Metrics: {"bytes_written":7138453,"delete_count":0,"lbm_write_time_us":7244,"lbm_writes_lt_1ms":177,"reinsert_count":0,"update_count":870}
I20260812 06:17:36.887642 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=1.000000
I20260812 06:17:37.046283 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.158s	user 0.110s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774701,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":328,"lbm_read_time_us":9900,"lbm_reads_lt_1ms":564,"lbm_write_time_us":25854,"lbm_writes_lt_1ms":543,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17024,"update_count":2500}
I20260812 06:17:37.046800 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=14.095187
I20260812 06:17:37.088096 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.041s	user 0.012s	sys 0.024s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":16368,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:37.088652 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=2.188937
I20260812 06:17:37.103844 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5596,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.104450 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=1.000000
I20260812 06:17:37.267596 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.163s	user 0.108s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":211,"lbm_read_time_us":9993,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27578,"lbm_writes_lt_1ms":543,"mutex_wait_us":31,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13568,"update_count":2500}
I20260812 06:17:37.268224 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=11.118625
I20260812 06:17:37.303566 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.035s	user 0.029s	sys 0.004s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14705,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:37.304069 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=2.188937
I20260812 06:17:37.316849 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4172,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:37.317371 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=1.000000
I20260812 06:17:37.438267 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.121s	user 0.097s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":178,"lbm_read_time_us":6789,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23755,"lbm_writes_lt_1ms":443,"mutex_wait_us":19,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6912,"update_count":2000}
I20260812 06:17:37.438840 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=10.126437
I20260812 06:17:37.477099 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.038s	user 0.020s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13193,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:37.477634 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=2.188937
I20260812 06:17:37.487444 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3582,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.487859 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=1.000000
I20260812 06:17:37.611161 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.123s	user 0.094s	sys 0.024s 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":128,"lbm_read_time_us":7915,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23715,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":2000}
I20260812 06:17:37.611732 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=10.126437
I20260812 06:17:37.662165 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.050s	user 0.020s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14026,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:37.662635 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=2.188937
I20260812 06:17:37.677913 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5853,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.678398 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushMRSOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=1.000000
I20260812 06:17:37.705469 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushMRSOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.027s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":242,"dirs.run_wall_time_us":1426,"drs_written":1,"lbm_read_time_us":35,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1244,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:37.706226 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=1.000000
I20260812 06:17:37.834767 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.128s	user 0.090s	sys 0.038s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":787,"lbm_read_time_us":8526,"lbm_reads_lt_1ms":464,"lbm_write_time_us":20124,"lbm_writes_lt_1ms":443,"mutex_wait_us":299,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:37.835343 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling LogGCOp(02df376b87404639b8fd63a7cb2c6ef7): free 121459513 bytes of WAL
I20260812 06:17:37.835614 10160 log_reader.cc:385] T 02df376b87404639b8fd63a7cb2c6ef7: removed 12 log segments from log reader
I20260812 06:17:37.835709 10160 log.cc:1079] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/02df376b87404639b8fd63a7cb2c6ef7/wal-000000015 (ops 71-75)
I20260812 06:17:37.835760 10160 log.cc:1079] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/02df376b87404639b8fd63a7cb2c6ef7/wal-000000016 (ops 76-80)
I20260812 06:17:37.835816 10160 log.cc:1079] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/02df376b87404639b8fd63a7cb2c6ef7/wal-000000017 (ops 81-85)
I20260812 06:17:37.835866 10160 log.cc:1079] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/02df376b87404639b8fd63a7cb2c6ef7/wal-000000018 (ops 86-90)
I20260812 06:17:37.835909 10160 log.cc:1079] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/02df376b87404639b8fd63a7cb2c6ef7/wal-000000019 (ops 91-95)
I20260812 06:17:37.835932 10160 log.cc:1079] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/02df376b87404639b8fd63a7cb2c6ef7/wal-000000020 (ops 96-100)
I20260812 06:17:37.835987 10160 log.cc:1079] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/02df376b87404639b8fd63a7cb2c6ef7/wal-000000021 (ops 101-105)
I20260812 06:17:37.836019 10160 log.cc:1079] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/02df376b87404639b8fd63a7cb2c6ef7/wal-000000022 (ops 106-110)
I20260812 06:17:37.836042 10160 log.cc:1079] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/02df376b87404639b8fd63a7cb2c6ef7/wal-000000023 (ops 111-115)
I20260812 06:17:37.836091 10160 log.cc:1079] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/02df376b87404639b8fd63a7cb2c6ef7/wal-000000024 (ops 116-120)
I20260812 06:17:37.836123 10160 log.cc:1079] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/02df376b87404639b8fd63a7cb2c6ef7/wal-000000025 (ops 121-125)
I20260812 06:17:37.836161 10160 log.cc:1079] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/02df376b87404639b8fd63a7cb2c6ef7/wal-000000026 (ops 126-130)
I20260812 06:17:37.861125 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: LogGCOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.026s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:17:37.861697 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=14.095187
I20260812 06:17:37.902557 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.040s	user 0.016s	sys 0.021s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18795,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:37.903100 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=2.188937
I20260812 06:17:37.917723 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.014s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5053,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.918193 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling UndoDeltaBlockGCOp(02df376b87404639b8fd63a7cb2c6ef7): 462 bytes on disk
I20260812 06:17:37.918605 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: UndoDeltaBlockGCOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:17:37.919184 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=1.000000
I20260812 06:17:38.074280 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.155s	user 0.094s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":436,"lbm_read_time_us":9520,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29190,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:17:38.074747 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=14.095187
I20260812 06:17:38.120950 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.046s	user 0.025s	sys 0.016s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19353,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:38.121567 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=2.188937
I20260812 06:17:38.136058 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.014s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5267,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:38.136533 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=1.000000
I20260812 06:17:38.280333 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.144s	user 0.101s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":239,"lbm_read_time_us":8214,"lbm_reads_lt_1ms":564,"lbm_write_time_us":26056,"lbm_writes_lt_1ms":543,"mutex_wait_us":28,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2500}
I20260812 06:17:38.280858 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=14.095187
I20260812 06:17:38.330618 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.050s	user 0.038s	sys 0.008s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20992,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:38.331195 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=2.188937
I20260812 06:17:38.346897 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.016s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5838,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:38.347536 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=1.000000
I20260812 06:17:38.484097 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.136s	user 0.110s	sys 0.025s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1162,"lbm_read_time_us":9295,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27723,"lbm_writes_lt_1ms":543,"mutex_wait_us":518,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":25728,"update_count":2500}
I20260812 06:17:38.484650 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=11.118625
I20260812 06:17:38.513834 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.029s	user 0.025s	sys 0.003s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":12441,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:38.514384 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=2.188937
I20260812 06:17:38.531702 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.017s	user 0.010s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4337,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:38.532445 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=1.000000
I20260812 06:17:38.646970 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.114s	user 0.081s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":865,"lbm_read_time_us":7055,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21590,"lbm_writes_lt_1ms":443,"mutex_wait_us":78,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:17:38.647523 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=11.118625
I20260812 06:17:38.684629 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.037s	user 0.011s	sys 0.023s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":12261,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:38.685142 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=2.188937
I20260812 06:17:38.697454 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3783,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:38.697995 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=1.000000
I20260812 06:17:38.843963 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.146s	user 0.115s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672267,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":170,"lbm_read_time_us":8686,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23368,"lbm_writes_lt_1ms":443,"mutex_wait_us":46,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9600,"update_count":2000}
I20260812 06:17:38.844524 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=10.126437
I20260812 06:17:38.875819 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.031s	user 0.017s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13496,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:38.876350 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=2.188937
I20260812 06:17:38.895460 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.019s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5739,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:38.896170 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=1.000000
I20260812 06:17:39.025354 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.129s	user 0.097s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":597,"lbm_read_time_us":7653,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22612,"lbm_writes_lt_1ms":443,"mutex_wait_us":253,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:17:39.025903 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=14.095187
I20260812 06:17:39.067201 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.041s	user 0.029s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":16969,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:39.067727 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=2.188937
I20260812 06:17:39.077845 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3603,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:39.078491 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushMRSOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=1.000000
I20260812 06:17:39.106914 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushMRSOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.028s	user 0.022s	sys 0.004s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":86,"dirs.run_cpu_time_us":332,"dirs.run_wall_time_us":1591,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1549,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:39.107806 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling LogGCOp(02df376b87404639b8fd63a7cb2c6ef7): free 136728511 bytes of WAL
I20260812 06:17:39.108069 10160 log_reader.cc:385] T 02df376b87404639b8fd63a7cb2c6ef7: removed 13 log segments from log reader
I20260812 06:17:39.108134 10160 log.cc:1079] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/02df376b87404639b8fd63a7cb2c6ef7/wal-000000027 (ops 131-135)
I20260812 06:17:39.108174 10160 log.cc:1079] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/02df376b87404639b8fd63a7cb2c6ef7/wal-000000028 (ops 136-140)
I20260812 06:17:39.108207 10160 log.cc:1079] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/02df376b87404639b8fd63a7cb2c6ef7/wal-000000029 (ops 141-145)
I20260812 06:17:39.108232 10160 log.cc:1079] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/02df376b87404639b8fd63a7cb2c6ef7/wal-000000030 (ops 146-150)
I20260812 06:17:39.108256 10160 log.cc:1079] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/02df376b87404639b8fd63a7cb2c6ef7/wal-000000031 (ops 151-155)
I20260812 06:17:39.108283 10160 log.cc:1079] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/02df376b87404639b8fd63a7cb2c6ef7/wal-000000032 (ops 156-160)
I20260812 06:17:39.108314 10160 log.cc:1079] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/02df376b87404639b8fd63a7cb2c6ef7/wal-000000033 (ops 161-165)
I20260812 06:17:39.108343 10160 log.cc:1079] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/02df376b87404639b8fd63a7cb2c6ef7/wal-000000034 (ops 166-170)
I20260812 06:17:39.108368 10160 log.cc:1079] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/02df376b87404639b8fd63a7cb2c6ef7/wal-000000035 (ops 171-175)
I20260812 06:17:39.108393 10160 log.cc:1079] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/02df376b87404639b8fd63a7cb2c6ef7/wal-000000036 (ops 176-180)
I20260812 06:17:39.108433 10160 log.cc:1079] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/02df376b87404639b8fd63a7cb2c6ef7/wal-000000037 (ops 181-185)
I20260812 06:17:39.108464 10160 log.cc:1079] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/02df376b87404639b8fd63a7cb2c6ef7/wal-000000038 (ops 186-190)
I20260812 06:17:39.108493 10160 log.cc:1079] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/02df376b87404639b8fd63a7cb2c6ef7/wal-000000039 (ops 191-195)
I20260812 06:17:39.137247 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: LogGCOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:17:39.137723 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling UndoDeltaBlockGCOp(02df376b87404639b8fd63a7cb2c6ef7): 493 bytes on disk
I20260812 06:17:39.138177 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: UndoDeltaBlockGCOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:17:39.138731 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=3.181125
I20260812 06:17:39.149977 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":4321,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:39.150444 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=2.188937
I20260812 06:17:39.159996 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3397,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:39.160643 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=1.000000
I20260812 06:17:39.238138  9968 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.586s	user 1.704s	sys 0.137s
I20260812 06:17:39.330699 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: MajorDeltaCompactionOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.170s	user 0.121s	sys 0.047s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979739,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":822,"lbm_read_time_us":12957,"lbm_reads_lt_1ms":770,"lbm_write_time_us":31206,"lbm_writes_lt_1ms":743,"mutex_wait_us":320,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":113,"threads_started":1,"update_count":3500}
I20260812 06:17:39.331442 10263 maintenance_manager.cc:419] P 624f4101226746eead34f8f30f0db2dc: Scheduling FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7): perf score=6.157687
I20260812 06:17:39.336091  9968 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.097s	user 0.004s	sys 0.000s
I20260812 06:17:39.336686  9968 tablet_server.cc:179] TabletServer@127.9.188.1:0 shutting down...
I20260812 06:17:39.383486 10160 maintenance_manager.cc:643] P 624f4101226746eead34f8f30f0db2dc: FlushDeltaMemStoresOp(02df376b87404639b8fd63a7cb2c6ef7) complete. Timing: real 0.051s	user 0.018s	sys 0.001s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":8741,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:39.384104  9968 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:39.384521  9968 tablet_replica.cc:333] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc: stopping tablet replica
I20260812 06:17:39.384737  9968 raft_consensus.cc:2243] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:39.385016  9968 raft_consensus.cc:2272] T 02df376b87404639b8fd63a7cb2c6ef7 P 624f4101226746eead34f8f30f0db2dc [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:39.399865  9968 tablet_server.cc:196] TabletServer@127.9.188.1:0 shutdown complete.
I20260812 06:17:39.404613  9968 master.cc:562] Master@127.9.188.62:37913 shutting down...
I20260812 06:17:39.407680  9968 raft_consensus.cc:2243] T 00000000000000000000000000000000 P cab1ab86f7dd44919bf14eb732816f64 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:39.407853  9968 raft_consensus.cc:2272] T 00000000000000000000000000000000 P cab1ab86f7dd44919bf14eb732816f64 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:39.407932  9968 tablet_replica.cc:333] T 00000000000000000000000000000000 P cab1ab86f7dd44919bf14eb732816f64: stopping tablet replica
I20260812 06:17:39.420151  9968 master.cc:584] Master@127.9.188.62:37913 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5136 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:39.506088  9968 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.9.188.62:42991
I20260812 06:17:39.506498  9968 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:39.508478 10326 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:39.508540 10330 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:17:39.508601 10327 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:17:39.508736  9968 server_base.cc:1061] running on GCE node
I20260812 06:17:39.508912  9968 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:39.508956  9968 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:17:39.508971  9968 hybrid_clock.cc:648] HybridClock initialized: now 1786515459508971 us; error 0 us; skew 500 ppm
I20260812 06:17:39.509814  9968 webserver.cc:533] Webserver started at http://127.9.188.62:34621/ using document root <none> and password file <none>
I20260812 06:17:39.510000  9968 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:39.510051  9968 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:39.510129  9968 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:39.510531  9968 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/master-0-root/instance:
uuid: "f41d4421efe148a4b0a42e13f828ad85"
format_stamp: "Formatted at 2026-08-12 06:17:39 on dist-test-slave-7lbf"
I20260812 06:17:39.511992  9968 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:39.512929 10339 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:17:39.513208  9968 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:39.513309  9968 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/master-0-root
uuid: "f41d4421efe148a4b0a42e13f828ad85"
format_stamp: "Formatted at 2026-08-12 06:17:39 on dist-test-slave-7lbf"
I20260812 06:17:39.513374  9968 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-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:17:39.518440  9968 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:39.518754  9968 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:39.522818  9968 rpc_server.cc:307] RPC server started. Bound to: 127.9.188.62:42991
I20260812 06:17:39.528442 10422 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.9.188.62:42991 every 8 connection(s)
I20260812 06:17:39.528929 10423 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:17:39.530725 10423 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P f41d4421efe148a4b0a42e13f828ad85: Bootstrap starting.
I20260812 06:17:39.531454 10423 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P f41d4421efe148a4b0a42e13f828ad85: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:39.532387 10423 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P f41d4421efe148a4b0a42e13f828ad85: No bootstrap required, opened a new log
I20260812 06:17:39.532768 10423 raft_consensus.cc:359] T 00000000000000000000000000000000 P f41d4421efe148a4b0a42e13f828ad85 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f41d4421efe148a4b0a42e13f828ad85" member_type: VOTER }
I20260812 06:17:39.532850 10423 raft_consensus.cc:385] T 00000000000000000000000000000000 P f41d4421efe148a4b0a42e13f828ad85 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:39.532878 10423 raft_consensus.cc:740] T 00000000000000000000000000000000 P f41d4421efe148a4b0a42e13f828ad85 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: f41d4421efe148a4b0a42e13f828ad85, State: Initialized, Role: FOLLOWER
I20260812 06:17:39.532987 10423 consensus_queue.cc:260] T 00000000000000000000000000000000 P f41d4421efe148a4b0a42e13f828ad85 [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: "f41d4421efe148a4b0a42e13f828ad85" member_type: VOTER }
I20260812 06:17:39.533042 10423 raft_consensus.cc:399] T 00000000000000000000000000000000 P f41d4421efe148a4b0a42e13f828ad85 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:39.533068 10423 raft_consensus.cc:493] T 00000000000000000000000000000000 P f41d4421efe148a4b0a42e13f828ad85 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:39.533100 10423 raft_consensus.cc:3060] T 00000000000000000000000000000000 P f41d4421efe148a4b0a42e13f828ad85 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:39.533825 10423 raft_consensus.cc:515] T 00000000000000000000000000000000 P f41d4421efe148a4b0a42e13f828ad85 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f41d4421efe148a4b0a42e13f828ad85" member_type: VOTER }
I20260812 06:17:39.533949 10423 leader_election.cc:304] T 00000000000000000000000000000000 P f41d4421efe148a4b0a42e13f828ad85 [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: f41d4421efe148a4b0a42e13f828ad85; no voters: 
I20260812 06:17:39.534101 10423 leader_election.cc:290] T 00000000000000000000000000000000 P f41d4421efe148a4b0a42e13f828ad85 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:39.534222 10427 raft_consensus.cc:2804] T 00000000000000000000000000000000 P f41d4421efe148a4b0a42e13f828ad85 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:39.534403 10427 raft_consensus.cc:697] T 00000000000000000000000000000000 P f41d4421efe148a4b0a42e13f828ad85 [term 1 LEADER]: Becoming Leader. State: Replica: f41d4421efe148a4b0a42e13f828ad85, State: Running, Role: LEADER
I20260812 06:17:39.534576 10423 sys_catalog.cc:565] T 00000000000000000000000000000000 P f41d4421efe148a4b0a42e13f828ad85 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:39.534570 10427 consensus_queue.cc:237] T 00000000000000000000000000000000 P f41d4421efe148a4b0a42e13f828ad85 [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: "f41d4421efe148a4b0a42e13f828ad85" member_type: VOTER }
I20260812 06:17:39.535035 10431 sys_catalog.cc:455] T 00000000000000000000000000000000 P f41d4421efe148a4b0a42e13f828ad85 [sys.catalog]: SysCatalogTable state changed. Reason: New leader f41d4421efe148a4b0a42e13f828ad85. Latest consensus state: current_term: 1 leader_uuid: "f41d4421efe148a4b0a42e13f828ad85" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f41d4421efe148a4b0a42e13f828ad85" member_type: VOTER } }
I20260812 06:17:39.535135 10431 sys_catalog.cc:458] T 00000000000000000000000000000000 P f41d4421efe148a4b0a42e13f828ad85 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:39.535003 10428 sys_catalog.cc:455] T 00000000000000000000000000000000 P f41d4421efe148a4b0a42e13f828ad85 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "f41d4421efe148a4b0a42e13f828ad85" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f41d4421efe148a4b0a42e13f828ad85" member_type: VOTER } }
I20260812 06:17:39.535368 10428 sys_catalog.cc:458] T 00000000000000000000000000000000 P f41d4421efe148a4b0a42e13f828ad85 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:39.535730 10434 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:39.536633 10434 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:39.536808  9968 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:39.538470 10434 catalog_manager.cc:1383] Generated new cluster ID: e79c5d7043254937926b10da90b6c92e
I20260812 06:17:39.538523 10434 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:39.552817 10434 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:39.553359 10434 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:39.557307 10434 catalog_manager.cc:6092] T 00000000000000000000000000000000 P f41d4421efe148a4b0a42e13f828ad85: Generated new TSK 0
I20260812 06:17:39.557458 10434 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:39.569177  9968 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:39.571007 10457 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:39.571010 10462 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:17:39.571148  9968 server_base.cc:1061] running on GCE node
W20260812 06:17:39.571125 10465 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:39.571444  9968 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:39.571494  9968 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:17:39.571514  9968 hybrid_clock.cc:648] HybridClock initialized: now 1786515459571514 us; error 0 us; skew 500 ppm
I20260812 06:17:39.572513  9968 webserver.cc:533] Webserver started at http://127.9.188.1:42051/ using document root <none> and password file <none>
I20260812 06:17:39.572682  9968 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:39.572729  9968 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:39.572785  9968 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:39.573108  9968 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root/instance:
uuid: "356d863a167e4a35b57444bc3281405a"
format_stamp: "Formatted at 2026-08-12 06:17:39 on dist-test-slave-7lbf"
I20260812 06:17:39.574519  9968 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:39.575347 10475 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:17:39.575590  9968 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:39.575654  9968 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root
uuid: "356d863a167e4a35b57444bc3281405a"
format_stamp: "Formatted at 2026-08-12 06:17:39 on dist-test-slave-7lbf"
I20260812 06:17:39.575724  9968 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-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:17:39.589946  9968 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:39.590320  9968 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:39.590626  9968 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:39.591097  9968 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:39.591221  9968 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:39.591339  9968 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:39.591375  9968 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:39.595927  9968 rpc_server.cc:307] RPC server started. Bound to: 127.9.188.1:39169
I20260812 06:17:39.595947 10579 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.9.188.1:39169 every 8 connection(s)
I20260812 06:17:39.604422 10580 heartbeater.cc:344] Connected to a master server at 127.9.188.62:42991
I20260812 06:17:39.604532 10580 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:39.604743 10580 heartbeater.cc:507] Master 127.9.188.62:42991 requested a full tablet report, sending...
I20260812 06:17:39.605338 10366 ts_manager.cc:194] Registered new tserver with Master: 356d863a167e4a35b57444bc3281405a (127.9.188.1:39169)
I20260812 06:17:39.606104 10366 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:47632
I20260812 06:17:39.606375  9968 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.010016798s
I20260812 06:17:39.612581 10366 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:47636:
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:17:39.620532 10522 tablet_service.cc:1511] Processing CreateTablet for tablet 83001097966f4c5cb3602bcf6876d30b (DEFAULT_TABLE table=heavy-update-compaction-test [id=5dd4332c439c4c56bd3c030f9e9eef34]), partition=
I20260812 06:17:39.620774 10522 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 83001097966f4c5cb3602bcf6876d30b. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:39.622705 10602 tablet_bootstrap.cc:492] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Bootstrap starting.
I20260812 06:17:39.623535 10602 tablet_bootstrap.cc:654] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:39.624486 10602 tablet_bootstrap.cc:492] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: No bootstrap required, opened a new log
I20260812 06:17:39.624558 10602 ts_tablet_manager.cc:1403] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:17:39.624907 10602 raft_consensus.cc:359] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "356d863a167e4a35b57444bc3281405a" member_type: VOTER last_known_addr { host: "127.9.188.1" port: 39169 } }
I20260812 06:17:39.624989 10602 raft_consensus.cc:385] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:39.625021 10602 raft_consensus.cc:740] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 356d863a167e4a35b57444bc3281405a, State: Initialized, Role: FOLLOWER
I20260812 06:17:39.625156 10602 consensus_queue.cc:260] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a [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: "356d863a167e4a35b57444bc3281405a" member_type: VOTER last_known_addr { host: "127.9.188.1" port: 39169 } }
I20260812 06:17:39.625224 10602 raft_consensus.cc:399] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:39.625260 10602 raft_consensus.cc:493] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:39.625308 10602 raft_consensus.cc:3060] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:39.626214 10602 raft_consensus.cc:515] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "356d863a167e4a35b57444bc3281405a" member_type: VOTER last_known_addr { host: "127.9.188.1" port: 39169 } }
I20260812 06:17:39.626338 10602 leader_election.cc:304] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a [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: 356d863a167e4a35b57444bc3281405a; no voters: 
I20260812 06:17:39.626524 10602 leader_election.cc:290] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:39.626631 10605 raft_consensus.cc:2804] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:39.626821 10580 heartbeater.cc:499] Master 127.9.188.62:42991 was elected leader, sending a full tablet report...
I20260812 06:17:39.626804 10602 ts_tablet_manager.cc:1434] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:39.626801 10605 raft_consensus.cc:697] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a [term 1 LEADER]: Becoming Leader. State: Replica: 356d863a167e4a35b57444bc3281405a, State: Running, Role: LEADER
I20260812 06:17:39.627003 10605 consensus_queue.cc:237] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a [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: "356d863a167e4a35b57444bc3281405a" member_type: VOTER last_known_addr { host: "127.9.188.1" port: 39169 } }
I20260812 06:17:39.628242 10366 catalog_manager.cc:5719] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a reported cstate change: term changed from 0 to 1, leader changed from <none> to 356d863a167e4a35b57444bc3281405a (127.9.188.1). New cstate: current_term: 1 leader_uuid: "356d863a167e4a35b57444bc3281405a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "356d863a167e4a35b57444bc3281405a" member_type: VOTER last_known_addr { host: "127.9.188.1" port: 39169 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:39.681938  9968 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.051s	user 0.014s	sys 0.008s
I20260812 06:17:39.846930 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushMRSOp(83001097966f4c5cb3602bcf6876d30b): perf score=23.023690
I20260812 06:17:39.997406 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushMRSOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.150s	user 0.107s	sys 0.040s Metrics: {"bytes_written":12307489,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":176,"dirs.run_wall_time_us":851,"drs_written":1,"lbm_read_time_us":35,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40334,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1500}
I20260812 06:17:39.998062 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling LogGCOp(83001097966f4c5cb3602bcf6876d30b): free 20743880 bytes of WAL
I20260812 06:17:39.998309 10484 log_reader.cc:385] T 83001097966f4c5cb3602bcf6876d30b: removed 2 log segments from log reader
I20260812 06:17:39.998376 10484 log.cc:1079] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/83001097966f4c5cb3602bcf6876d30b/wal-000000001 (ops 1-6)
I20260812 06:17:39.998422 10484 log.cc:1079] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/83001097966f4c5cb3602bcf6876d30b/wal-000000002 (ops 7-11)
I20260812 06:17:40.003803 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: LogGCOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.006s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:17:40.004253 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling UndoDeltaBlockGCOp(83001097966f4c5cb3602bcf6876d30b): 20513814 bytes on disk
I20260812 06:17:40.004701 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: UndoDeltaBlockGCOp(83001097966f4c5cb3602bcf6876d30b) 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:17:40.005069 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b): perf score=3.181125
I20260812 06:17:40.018736 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.014s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4108,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:40.019165 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling MajorDeltaCompactionOp(83001097966f4c5cb3602bcf6876d30b): perf score=1.000000
I20260812 06:17:40.186813 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: MajorDeltaCompactionOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.167s	user 0.098s	sys 0.065s Metrics: {"cfile_cache_miss":442,"cfile_cache_miss_bytes":21123515,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":586,"lbm_read_time_us":11440,"lbm_reads_lt_1ms":470,"lbm_write_time_us":27746,"lbm_writes_lt_1ms":453,"peak_mem_usage":51099678,"reinsert_count":0,"spinlock_wait_cycles":2176,"thread_start_us":280,"threads_started":5,"update_count":2050}
I20260812 06:17:40.187327 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b): perf score=14.095187
I20260812 06:17:40.247154 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.059s	user 0.032s	sys 0.026s Metrics: {"bytes_written":15999660,"delete_count":0,"lbm_write_time_us":22316,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":392,"reinsert_count":0,"update_count":1950}
I20260812 06:17:40.247663 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b): perf score=2.188937
I20260812 06:17:40.258406 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.011s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3983,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:40.258988 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling MajorDeltaCompactionOp(83001097966f4c5cb3602bcf6876d30b): perf score=1.000000
I20260812 06:17:40.420414 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: MajorDeltaCompactionOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.161s	user 0.101s	sys 0.057s Metrics: {"cfile_cache_miss":522,"cfile_cache_miss_bytes":24405442,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1179,"lbm_read_time_us":12412,"lbm_reads_lt_1ms":562,"lbm_write_time_us":25907,"lbm_writes_lt_1ms":533,"mutex_wait_us":690,"peak_mem_usage":61665166,"reinsert_count":0,"update_count":2450}
I20260812 06:17:40.421087 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b): perf score=11.118625
I20260812 06:17:40.455108 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.034s	user 0.029s	sys 0.003s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13833,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:40.455673 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b): perf score=2.188937
I20260812 06:17:40.476769 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.021s	user 0.009s	sys 0.006s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4201,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:40.477770 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b): perf score=1.000000
I20260812 06:17:40.487078 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.009s	user 0.002s	sys 0.001s Metrics: {"bytes_written":1312956,"delete_count":0,"lbm_write_time_us":1275,"lbm_writes_lt_1ms":35,"reinsert_count":0,"update_count":160}
I20260812 06:17:40.487532 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b): perf score=1.196750
I20260812 06:17:40.495077 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.007s	user 0.003s	sys 0.003s Metrics: {"bytes_written":2789855,"delete_count":0,"lbm_write_time_us":2709,"lbm_writes_lt_1ms":71,"reinsert_count":0,"update_count":340}
I20260812 06:17:40.495529 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling MajorDeltaCompactionOp(83001097966f4c5cb3602bcf6876d30b): perf score=1.000000
I20260812 06:17:40.676765 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: MajorDeltaCompactionOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.181s	user 0.133s	sys 0.037s Metrics: {"cfile_cache_miss":534,"cfile_cache_miss_bytes":24815819,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":205,"lbm_read_time_us":12869,"lbm_reads_lt_1ms":574,"lbm_write_time_us":26772,"lbm_writes_lt_1ms":543,"mutex_wait_us":32,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9344,"update_count":2500}
I20260812 06:17:40.677302 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b): perf score=14.095187
I20260812 06:17:40.727170 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.050s	user 0.025s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24161,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:17:40.727707 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b): perf score=2.188937
I20260812 06:17:40.748345 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.020s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4720,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:40.748955 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling MajorDeltaCompactionOp(83001097966f4c5cb3602bcf6876d30b): perf score=1.000000
I20260812 06:17:40.918341 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: MajorDeltaCompactionOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.169s	user 0.117s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":155,"lbm_read_time_us":11272,"lbm_reads_lt_1ms":564,"lbm_write_time_us":25573,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2500}
I20260812 06:17:40.918854 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b): perf score=14.095187
I20260812 06:17:40.970891 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.052s	user 0.035s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22057,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:40.971396 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b): perf score=2.188937
I20260812 06:17:40.987308 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.016s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4710,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:40.987808 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling MajorDeltaCompactionOp(83001097966f4c5cb3602bcf6876d30b): perf score=1.000000
I20260812 06:17:41.163218 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: MajorDeltaCompactionOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.175s	user 0.092s	sys 0.075s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":282,"lbm_read_time_us":10408,"lbm_reads_lt_1ms":568,"lbm_write_time_us":26064,"lbm_writes_lt_1ms":543,"mutex_wait_us":71,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12416,"update_count":2500}
I20260812 06:17:41.163866 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b): perf score=14.095187
I20260812 06:17:41.207517 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.043s	user 0.030s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19276,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:41.208191 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b): perf score=2.188937
I20260812 06:17:41.223845 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.015s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6286,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:41.224471 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushMRSOp(83001097966f4c5cb3602bcf6876d30b): perf score=1.000000
I20260812 06:17:41.254767 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushMRSOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.030s	user 0.025s	sys 0.004s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":258,"dirs.run_wall_time_us":1299,"drs_written":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1445,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:41.255334 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling LogGCOp(83001097966f4c5cb3602bcf6876d30b): free 124710297 bytes of WAL
I20260812 06:17:41.255548 10484 log_reader.cc:385] T 83001097966f4c5cb3602bcf6876d30b: removed 12 log segments from log reader
I20260812 06:17:41.255592 10484 log.cc:1079] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/83001097966f4c5cb3602bcf6876d30b/wal-000000003 (ops 12-16)
I20260812 06:17:41.255621 10484 log.cc:1079] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/83001097966f4c5cb3602bcf6876d30b/wal-000000004 (ops 17-21)
I20260812 06:17:41.255651 10484 log.cc:1079] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/83001097966f4c5cb3602bcf6876d30b/wal-000000005 (ops 22-26)
I20260812 06:17:41.255682 10484 log.cc:1079] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/83001097966f4c5cb3602bcf6876d30b/wal-000000006 (ops 27-31)
I20260812 06:17:41.255714 10484 log.cc:1079] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/83001097966f4c5cb3602bcf6876d30b/wal-000000007 (ops 32-36)
I20260812 06:17:41.255748 10484 log.cc:1079] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/83001097966f4c5cb3602bcf6876d30b/wal-000000008 (ops 37-41)
I20260812 06:17:41.255779 10484 log.cc:1079] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/83001097966f4c5cb3602bcf6876d30b/wal-000000009 (ops 42-46)
I20260812 06:17:41.255810 10484 log.cc:1079] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/83001097966f4c5cb3602bcf6876d30b/wal-000000010 (ops 47-51)
I20260812 06:17:41.255841 10484 log.cc:1079] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/83001097966f4c5cb3602bcf6876d30b/wal-000000011 (ops 52-56)
I20260812 06:17:41.255872 10484 log.cc:1079] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/83001097966f4c5cb3602bcf6876d30b/wal-000000012 (ops 57-61)
I20260812 06:17:41.255895 10484 log.cc:1079] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/83001097966f4c5cb3602bcf6876d30b/wal-000000013 (ops 62-66)
I20260812 06:17:41.255925 10484 log.cc:1079] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/83001097966f4c5cb3602bcf6876d30b/wal-000000014 (ops 67-71)
I20260812 06:17:41.279189 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: LogGCOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.024s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:17:41.279690 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling UndoDeltaBlockGCOp(83001097966f4c5cb3602bcf6876d30b): 463 bytes on disk
I20260812 06:17:41.280252 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: UndoDeltaBlockGCOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:17:41.280800 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b): perf score=4.173312
I20260812 06:17:41.297403 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.016s	user 0.007s	sys 0.007s Metrics: {"bytes_written":5415441,"delete_count":0,"lbm_write_time_us":6514,"lbm_writes_lt_1ms":135,"reinsert_count":0,"update_count":660}
I20260812 06:17:41.297818 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b): perf score=1.196750
I20260812 06:17:41.309075 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":2789855,"delete_count":0,"lbm_write_time_us":3869,"lbm_writes_lt_1ms":71,"reinsert_count":0,"update_count":340}
I20260812 06:17:41.309544 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling MajorDeltaCompactionOp(83001097966f4c5cb3602bcf6876d30b): perf score=1.000000
I20260812 06:17:41.538617 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: MajorDeltaCompactionOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.229s	user 0.151s	sys 0.067s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020719,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":910,"lbm_read_time_us":15595,"lbm_reads_lt_1ms":774,"lbm_write_time_us":34210,"lbm_writes_lt_1ms":743,"mutex_wait_us":24,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":17280,"thread_start_us":82,"threads_started":1,"update_count":3500}
I20260812 06:17:41.539084 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b): perf score=18.063937
I20260812 06:17:41.616153 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.077s	user 0.050s	sys 0.016s Metrics: {"bytes_written":20512321,"delete_count":0,"lbm_write_time_us":31892,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:41.616703 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b): perf score=2.188937
I20260812 06:17:41.628613 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4172,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:41.629112 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling MajorDeltaCompactionOp(83001097966f4c5cb3602bcf6876d30b): perf score=1.000000
I20260812 06:17:41.825779 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: MajorDeltaCompactionOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.196s	user 0.141s	sys 0.055s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":178,"lbm_read_time_us":13813,"lbm_reads_lt_1ms":672,"lbm_write_time_us":31400,"lbm_writes_lt_1ms":643,"mutex_wait_us":28,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10240,"update_count":3000}
I20260812 06:17:41.826386 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b): perf score=14.095187
I20260812 06:17:41.869045 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.042s	user 0.023s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18964,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:41.869658 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b): perf score=2.188937
I20260812 06:17:41.885076 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6070,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:41.885654 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling MajorDeltaCompactionOp(83001097966f4c5cb3602bcf6876d30b): perf score=1.000000
I20260812 06:17:42.051647 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: MajorDeltaCompactionOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.166s	user 0.100s	sys 0.066s 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":168,"lbm_read_time_us":11268,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26897,"lbm_writes_lt_1ms":543,"mutex_wait_us":60,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2500}
I20260812 06:17:42.052170 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b): perf score=14.095187
I20260812 06:17:42.105979 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.054s	user 0.025s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21013,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:42.106510 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b): perf score=2.188937
I20260812 06:17:42.119571 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5088,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:42.120172 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling MajorDeltaCompactionOp(83001097966f4c5cb3602bcf6876d30b): perf score=1.000000
I20260812 06:17:42.289413 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: MajorDeltaCompactionOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.169s	user 0.116s	sys 0.048s 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":150,"lbm_read_time_us":11412,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26795,"lbm_writes_lt_1ms":543,"mutex_wait_us":34,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":2500}
I20260812 06:17:42.289961 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b): perf score=14.095187
I20260812 06:17:42.350653 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.061s	user 0.029s	sys 0.030s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":21787,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:42.351243 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b): perf score=2.188937
I20260812 06:17:42.366328 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5755,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:42.366824 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling MajorDeltaCompactionOp(83001097966f4c5cb3602bcf6876d30b): perf score=1.000000
I20260812 06:17:42.531116 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: MajorDeltaCompactionOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.164s	user 0.118s	sys 0.043s 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":244,"lbm_read_time_us":11365,"lbm_reads_lt_1ms":572,"lbm_write_time_us":24873,"lbm_writes_lt_1ms":543,"mutex_wait_us":18,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7296,"update_count":2500}
I20260812 06:17:42.531656 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b): perf score=14.095187
I20260812 06:17:42.590184 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.058s	user 0.019s	sys 0.035s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20479,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:42.590790 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b): perf score=2.188937
I20260812 06:17:42.601181 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3952,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:42.601656 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushMRSOp(83001097966f4c5cb3602bcf6876d30b): perf score=1.000000
I20260812 06:17:42.631930 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushMRSOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.030s	user 0.024s	sys 0.000s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":244,"dirs.run_wall_time_us":1352,"drs_written":1,"lbm_read_time_us":35,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1277,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:42.632609 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling MajorDeltaCompactionOp(83001097966f4c5cb3602bcf6876d30b): perf score=1.000000
I20260812 06:17:42.806506 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: MajorDeltaCompactionOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.174s	user 0.104s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":527,"lbm_read_time_us":13343,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27503,"lbm_writes_lt_1ms":543,"mutex_wait_us":101,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":2500}
I20260812 06:17:42.807159 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling LogGCOp(83001097966f4c5cb3602bcf6876d30b): free 112239321 bytes of WAL
I20260812 06:17:42.807442 10484 log_reader.cc:385] T 83001097966f4c5cb3602bcf6876d30b: removed 11 log segments from log reader
I20260812 06:17:42.807531 10484 log.cc:1079] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/83001097966f4c5cb3602bcf6876d30b/wal-000000015 (ops 72-76)
I20260812 06:17:42.807596 10484 log.cc:1079] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/83001097966f4c5cb3602bcf6876d30b/wal-000000016 (ops 77-80)
I20260812 06:17:42.807638 10484 log.cc:1079] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/83001097966f4c5cb3602bcf6876d30b/wal-000000017 (ops 81-85)
I20260812 06:17:42.807682 10484 log.cc:1079] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/83001097966f4c5cb3602bcf6876d30b/wal-000000018 (ops 86-90)
I20260812 06:17:42.807723 10484 log.cc:1079] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/83001097966f4c5cb3602bcf6876d30b/wal-000000019 (ops 91-95)
I20260812 06:17:42.807763 10484 log.cc:1079] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/83001097966f4c5cb3602bcf6876d30b/wal-000000020 (ops 96-100)
I20260812 06:17:42.807806 10484 log.cc:1079] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/83001097966f4c5cb3602bcf6876d30b/wal-000000021 (ops 101-105)
I20260812 06:17:42.807845 10484 log.cc:1079] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/83001097966f4c5cb3602bcf6876d30b/wal-000000022 (ops 106-110)
I20260812 06:17:42.807966 10484 log.cc:1079] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/83001097966f4c5cb3602bcf6876d30b/wal-000000023 (ops 111-115)
I20260812 06:17:42.808024 10484 log.cc:1079] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/83001097966f4c5cb3602bcf6876d30b/wal-000000024 (ops 116-120)
I20260812 06:17:42.808065 10484 log.cc:1079] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/83001097966f4c5cb3602bcf6876d30b/wal-000000025 (ops 121-125)
I20260812 06:17:42.830461 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: LogGCOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.023s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:17:42.830967 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling UndoDeltaBlockGCOp(83001097966f4c5cb3602bcf6876d30b): 447 bytes on disk
I20260812 06:17:42.831475 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: UndoDeltaBlockGCOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4}
I20260812 06:17:42.832125 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b): perf score=18.063937
I20260812 06:17:42.902765 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.070s	user 0.024s	sys 0.045s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":29221,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:17:42.903383 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b): perf score=2.188937
I20260812 06:17:42.917614 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.014s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5633,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:42.918215 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling MajorDeltaCompactionOp(83001097966f4c5cb3602bcf6876d30b): perf score=1.000000
I20260812 06:17:43.124292 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: MajorDeltaCompactionOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.206s	user 0.135s	sys 0.059s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918099,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":531,"lbm_read_time_us":14197,"lbm_reads_lt_1ms":668,"lbm_write_time_us":30353,"lbm_writes_lt_1ms":643,"mutex_wait_us":255,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":3000}
I20260812 06:17:43.124881 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b): perf score=18.063937
I20260812 06:17:43.186264 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.061s	user 0.045s	sys 0.016s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":26185,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:43.186882 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b): perf score=2.188937
I20260812 06:17:43.204778 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.018s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6399,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:43.205492 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling MajorDeltaCompactionOp(83001097966f4c5cb3602bcf6876d30b): perf score=1.000000
I20260812 06:17:43.417838 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: MajorDeltaCompactionOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.212s	user 0.148s	sys 0.054s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918100,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":666,"lbm_read_time_us":14851,"lbm_reads_lt_1ms":664,"lbm_write_time_us":32663,"lbm_writes_lt_1ms":643,"mutex_wait_us":58,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":8704,"update_count":3000}
I20260812 06:17:43.418483 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b): perf score=18.063937
I20260812 06:17:43.473826 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.055s	user 0.028s	sys 0.024s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":24239,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:43.474310 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling MajorDeltaCompactionOp(83001097966f4c5cb3602bcf6876d30b): perf score=1.000000
I20260812 06:17:43.631883 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: MajorDeltaCompactionOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.157s	user 0.125s	sys 0.032s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24815567,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":819,"lbm_read_time_us":10954,"lbm_reads_lt_1ms":563,"lbm_write_time_us":26589,"lbm_writes_lt_1ms":543,"mutex_wait_us":257,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9344,"update_count":2500}
I20260812 06:17:43.632421 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b): perf score=14.095187
I20260812 06:17:43.683266 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.051s	user 0.022s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17740,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:43.683781 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b): perf score=2.188937
I20260812 06:17:43.698601 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.015s	user 0.004s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5651,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:43.699092 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling MajorDeltaCompactionOp(83001097966f4c5cb3602bcf6876d30b): perf score=1.000000
I20260812 06:17:43.866923 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: MajorDeltaCompactionOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.168s	user 0.101s	sys 0.056s 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":884,"lbm_read_time_us":11753,"lbm_reads_lt_1ms":572,"lbm_write_time_us":24816,"lbm_writes_lt_1ms":543,"mutex_wait_us":262,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2500}
I20260812 06:17:43.867446 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b): perf score=14.095187
I20260812 06:17:43.923152 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.056s	user 0.027s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20605,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:43.923748 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b): perf score=2.188937
I20260812 06:17:43.934964 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4245,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:43.935472 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling MajorDeltaCompactionOp(83001097966f4c5cb3602bcf6876d30b): perf score=1.000000
I20260812 06:17:44.114187 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: MajorDeltaCompactionOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.179s	user 0.108s	sys 0.064s 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":276,"lbm_read_time_us":11990,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27471,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4736,"update_count":2500}
I20260812 06:17:44.114720 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b): perf score=14.095187
I20260812 06:17:44.171571 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.057s	user 0.026s	sys 0.028s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":26635,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:44.172222 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b): perf score=2.188937
I20260812 06:17:44.185148 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.013s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4382,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:44.185696 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushMRSOp(83001097966f4c5cb3602bcf6876d30b): perf score=1.000000
I20260812 06:17:44.217854 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushMRSOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.032s	user 0.031s	sys 0.001s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":238,"dirs.run_wall_time_us":1225,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1962,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:44.218596 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling LogGCOp(83001097966f4c5cb3602bcf6876d30b): free 133024632 bytes of WAL
I20260812 06:17:44.218844 10484 log_reader.cc:385] T 83001097966f4c5cb3602bcf6876d30b: removed 13 log segments from log reader
I20260812 06:17:44.218907 10484 log.cc:1079] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/83001097966f4c5cb3602bcf6876d30b/wal-000000026 (ops 126-130)
I20260812 06:17:44.218945 10484 log.cc:1079] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/83001097966f4c5cb3602bcf6876d30b/wal-000000027 (ops 131-135)
I20260812 06:17:44.218982 10484 log.cc:1079] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/83001097966f4c5cb3602bcf6876d30b/wal-000000028 (ops 136-140)
I20260812 06:17:44.219017 10484 log.cc:1079] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/83001097966f4c5cb3602bcf6876d30b/wal-000000029 (ops 141-144)
I20260812 06:17:44.219048 10484 log.cc:1079] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/83001097966f4c5cb3602bcf6876d30b/wal-000000030 (ops 145-149)
I20260812 06:17:44.219072 10484 log.cc:1079] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/83001097966f4c5cb3602bcf6876d30b/wal-000000031 (ops 150-154)
I20260812 06:17:44.219096 10484 log.cc:1079] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/83001097966f4c5cb3602bcf6876d30b/wal-000000032 (ops 155-159)
I20260812 06:17:44.219123 10484 log.cc:1079] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/83001097966f4c5cb3602bcf6876d30b/wal-000000033 (ops 160-164)
I20260812 06:17:44.219152 10484 log.cc:1079] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/83001097966f4c5cb3602bcf6876d30b/wal-000000034 (ops 165-169)
I20260812 06:17:44.219183 10484 log.cc:1079] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/83001097966f4c5cb3602bcf6876d30b/wal-000000035 (ops 170-174)
I20260812 06:17:44.219211 10484 log.cc:1079] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/83001097966f4c5cb3602bcf6876d30b/wal-000000036 (ops 175-179)
I20260812 06:17:44.219236 10484 log.cc:1079] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/83001097966f4c5cb3602bcf6876d30b/wal-000000037 (ops 180-184)
I20260812 06:17:44.219260 10484 log.cc:1079] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: Deleting log segment in path: /tmp/dist-test-taskbNqfpI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515454346622-9968-0/minicluster-data/ts-0-root/wals/83001097966f4c5cb3602bcf6876d30b/wal-000000038 (ops 185-189)
I20260812 06:17:44.247968 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: LogGCOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.029s	user 0.004s	sys 0.023s Metrics: {}
I20260812 06:17:44.248418 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling UndoDeltaBlockGCOp(83001097966f4c5cb3602bcf6876d30b): 493 bytes on disk
I20260812 06:17:44.248917 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: UndoDeltaBlockGCOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:17:44.249506 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b): perf score=3.181125
I20260812 06:17:44.269685 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.020s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6552,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:44.270119 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b): perf score=2.188937
I20260812 06:17:44.279242 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3404,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:44.279670 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling MajorDeltaCompactionOp(83001097966f4c5cb3602bcf6876d30b): perf score=1.000000
I20260812 06:17:44.440079  9968 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.758s	user 1.680s	sys 0.191s
I20260812 06:17:44.495710 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: MajorDeltaCompactionOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.216s	user 0.142s	sys 0.071s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020737,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":13627,"lbm_reads_lt_1ms":770,"lbm_write_time_us":34549,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":3500}
I20260812 06:17:44.496280 10581 maintenance_manager.cc:419] P 356d863a167e4a35b57444bc3281405a: Scheduling FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b): perf score=14.095187
I20260812 06:17:44.553759  9968 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.113s	user 0.003s	sys 0.000s
I20260812 06:17:44.554286  9968 tablet_server.cc:179] TabletServer@127.9.188.1:0 shutting down...
I20260812 06:17:44.591828 10484 maintenance_manager.cc:643] P 356d863a167e4a35b57444bc3281405a: FlushDeltaMemStoresOp(83001097966f4c5cb3602bcf6876d30b) complete. Timing: real 0.095s	user 0.036s	sys 0.011s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22163,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:44.592378  9968 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:44.592578  9968 tablet_replica.cc:333] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a: stopping tablet replica
I20260812 06:17:44.592717  9968 raft_consensus.cc:2243] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:44.592873  9968 raft_consensus.cc:2272] T 83001097966f4c5cb3602bcf6876d30b P 356d863a167e4a35b57444bc3281405a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:44.595861  9968 tablet_server.cc:196] TabletServer@127.9.188.1:0 shutdown complete.
I20260812 06:17:44.598362  9968 master.cc:562] Master@127.9.188.62:42991 shutting down...
I20260812 06:17:44.601486  9968 raft_consensus.cc:2243] T 00000000000000000000000000000000 P f41d4421efe148a4b0a42e13f828ad85 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:44.601665  9968 raft_consensus.cc:2272] T 00000000000000000000000000000000 P f41d4421efe148a4b0a42e13f828ad85 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:44.601717  9968 tablet_replica.cc:333] T 00000000000000000000000000000000 P f41d4421efe148a4b0a42e13f828ad85: stopping tablet replica
I20260812 06:17:44.613670  9968 master.cc:584] Master@127.9.188.62:42991 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5195 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10332 ms total)

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