[==========] 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:54.561410 25072 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.24.124.62:35041
I20260812 06:17:54.562879 25072 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:54.563577 25072 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:54.571883 25077 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:54.571938 25072 server_base.cc:1061] running on GCE node
W20260812 06:17:54.571885 25080 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:54.572216 25078 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:54.572942 25072 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:54.573084 25072 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:54.573143 25072 hybrid_clock.cc:648] HybridClock initialized: now 1786515474573140 us; error 0 us; skew 500 ppm
I20260812 06:17:54.575845 25072 webserver.cc:533] Webserver started at http://127.24.124.62:37527/ using document root <none> and password file <none>
I20260812 06:17:54.576627 25072 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:54.576732 25072 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:54.577045 25072 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:54.579713 25072 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/master-0-root/instance:
uuid: "19600b197ccb485c8185f0d8034f54e7"
format_stamp: "Formatted at 2026-08-12 06:17:54 on dist-test-slave-njxd"
I20260812 06:17:54.584830 25072 fs_manager.cc:696] Time spent creating directory manager: real 0.005s	user 0.006s	sys 0.000s
I20260812 06:17:54.587572 25086 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:54.588660 25072 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:17:54.588811 25072 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/master-0-root
uuid: "19600b197ccb485c8185f0d8034f54e7"
format_stamp: "Formatted at 2026-08-12 06:17:54 on dist-test-slave-njxd"
I20260812 06:17:54.588932 25072 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-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:54.607731 25072 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:54.608462 25072 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:54.608665 25072 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:54.616775 25072 rpc_server.cc:307] RPC server started. Bound to: 127.24.124.62:35041
I20260812 06:17:54.616824 25144 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.124.62:35041 every 8 connection(s)
I20260812 06:17:54.619190 25145 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:54.625435 25145 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 19600b197ccb485c8185f0d8034f54e7: Bootstrap starting.
I20260812 06:17:54.628014 25145 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 19600b197ccb485c8185f0d8034f54e7: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:54.629060 25145 log.cc:826] T 00000000000000000000000000000000 P 19600b197ccb485c8185f0d8034f54e7: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:54.631016 25145 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 19600b197ccb485c8185f0d8034f54e7: No bootstrap required, opened a new log
I20260812 06:17:54.634173 25145 raft_consensus.cc:359] T 00000000000000000000000000000000 P 19600b197ccb485c8185f0d8034f54e7 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "19600b197ccb485c8185f0d8034f54e7" member_type: VOTER }
I20260812 06:17:54.634390 25145 raft_consensus.cc:385] T 00000000000000000000000000000000 P 19600b197ccb485c8185f0d8034f54e7 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:54.634488 25145 raft_consensus.cc:740] T 00000000000000000000000000000000 P 19600b197ccb485c8185f0d8034f54e7 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 19600b197ccb485c8185f0d8034f54e7, State: Initialized, Role: FOLLOWER
I20260812 06:17:54.635277 25145 consensus_queue.cc:260] T 00000000000000000000000000000000 P 19600b197ccb485c8185f0d8034f54e7 [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: "19600b197ccb485c8185f0d8034f54e7" member_type: VOTER }
I20260812 06:17:54.635476 25145 raft_consensus.cc:399] T 00000000000000000000000000000000 P 19600b197ccb485c8185f0d8034f54e7 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:54.635558 25145 raft_consensus.cc:493] T 00000000000000000000000000000000 P 19600b197ccb485c8185f0d8034f54e7 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:54.635748 25145 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 19600b197ccb485c8185f0d8034f54e7 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:54.636687 25145 raft_consensus.cc:515] T 00000000000000000000000000000000 P 19600b197ccb485c8185f0d8034f54e7 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "19600b197ccb485c8185f0d8034f54e7" member_type: VOTER }
I20260812 06:17:54.637202 25145 leader_election.cc:304] T 00000000000000000000000000000000 P 19600b197ccb485c8185f0d8034f54e7 [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: 19600b197ccb485c8185f0d8034f54e7; no voters: 
I20260812 06:17:54.637663 25145 leader_election.cc:290] T 00000000000000000000000000000000 P 19600b197ccb485c8185f0d8034f54e7 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:54.637853 25148 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 19600b197ccb485c8185f0d8034f54e7 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:54.638134 25148 raft_consensus.cc:697] T 00000000000000000000000000000000 P 19600b197ccb485c8185f0d8034f54e7 [term 1 LEADER]: Becoming Leader. State: Replica: 19600b197ccb485c8185f0d8034f54e7, State: Running, Role: LEADER
I20260812 06:17:54.638644 25148 consensus_queue.cc:237] T 00000000000000000000000000000000 P 19600b197ccb485c8185f0d8034f54e7 [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: "19600b197ccb485c8185f0d8034f54e7" member_type: VOTER }
I20260812 06:17:54.638809 25145 sys_catalog.cc:565] T 00000000000000000000000000000000 P 19600b197ccb485c8185f0d8034f54e7 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:54.640805 25151 sys_catalog.cc:455] T 00000000000000000000000000000000 P 19600b197ccb485c8185f0d8034f54e7 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 19600b197ccb485c8185f0d8034f54e7. Latest consensus state: current_term: 1 leader_uuid: "19600b197ccb485c8185f0d8034f54e7" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "19600b197ccb485c8185f0d8034f54e7" member_type: VOTER } }
I20260812 06:17:54.640801 25149 sys_catalog.cc:455] T 00000000000000000000000000000000 P 19600b197ccb485c8185f0d8034f54e7 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "19600b197ccb485c8185f0d8034f54e7" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "19600b197ccb485c8185f0d8034f54e7" member_type: VOTER } }
I20260812 06:17:54.640959 25151 sys_catalog.cc:458] T 00000000000000000000000000000000 P 19600b197ccb485c8185f0d8034f54e7 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:54.640959 25149 sys_catalog.cc:458] T 00000000000000000000000000000000 P 19600b197ccb485c8185f0d8034f54e7 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:54.641312 25072 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:54.641464 25163 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:54.643847 25163 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:54.648435 25163 catalog_manager.cc:1383] Generated new cluster ID: c5edd3f1500f416c8d2506745ad1dc49
I20260812 06:17:54.648515 25163 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:54.671360 25163 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:54.672343 25163 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:54.681555 25163 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 19600b197ccb485c8185f0d8034f54e7: Generated new TSK 0
I20260812 06:17:54.682366 25163 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:54.706421 25072 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:54.709722 25169 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:54.709713 25170 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:54.709720 25172 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:54.709896 25072 server_base.cc:1061] running on GCE node
I20260812 06:17:54.710248 25072 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:54.710304 25072 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:54.710330 25072 hybrid_clock.cc:648] HybridClock initialized: now 1786515474710329 us; error 0 us; skew 500 ppm
I20260812 06:17:54.711308 25072 webserver.cc:533] Webserver started at http://127.24.124.1:42413/ using document root <none> and password file <none>
I20260812 06:17:54.711483 25072 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:54.711541 25072 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:54.711611 25072 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:54.712059 25072 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root/instance:
uuid: "cac67b0310d349efaa92c24660ae28ff"
format_stamp: "Formatted at 2026-08-12 06:17:54 on dist-test-slave-njxd"
I20260812 06:17:54.713979 25072 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:17:54.715112 25177 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:54.715412 25072 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:54.715476 25072 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root
uuid: "cac67b0310d349efaa92c24660ae28ff"
format_stamp: "Formatted at 2026-08-12 06:17:54 on dist-test-slave-njxd"
I20260812 06:17:54.715576 25072 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-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:54.725412 25072 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:54.725937 25072 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:54.726473 25072 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:54.727331 25072 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:54.727382 25072 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:54.727449 25072 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:54.727495 25072 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:54.734520 25072 rpc_server.cc:307] RPC server started. Bound to: 127.24.124.1:40659
I20260812 06:17:54.734830 25249 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.124.1:40659 every 8 connection(s)
I20260812 06:17:54.745625 25250 heartbeater.cc:344] Connected to a master server at 127.24.124.62:35041
I20260812 06:17:54.745908 25250 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:54.746429 25250 heartbeater.cc:507] Master 127.24.124.62:35041 requested a full tablet report, sending...
I20260812 06:17:54.748111 25104 ts_manager.cc:194] Registered new tserver with Master: cac67b0310d349efaa92c24660ae28ff (127.24.124.1:40659)
I20260812 06:17:54.748860 25072 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.013601874s
I20260812 06:17:54.749640 25104 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:39308
I20260812 06:17:54.759480 25104 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:39316:
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:54.775863 25209 tablet_service.cc:1511] Processing CreateTablet for tablet 37cde09350ec45bf99da5cb64b61a29f (DEFAULT_TABLE table=heavy-update-compaction-test [id=36f6cc0d8c2443ac9154695dffbdf8a0]), partition=
I20260812 06:17:54.776329 25209 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 37cde09350ec45bf99da5cb64b61a29f. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:54.778764 25263 tablet_bootstrap.cc:492] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Bootstrap starting.
I20260812 06:17:54.779788 25263 tablet_bootstrap.cc:654] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:54.781013 25263 tablet_bootstrap.cc:492] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: No bootstrap required, opened a new log
I20260812 06:17:54.781158 25263 ts_tablet_manager.cc:1403] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:54.781683 25263 raft_consensus.cc:359] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cac67b0310d349efaa92c24660ae28ff" member_type: VOTER last_known_addr { host: "127.24.124.1" port: 40659 } }
I20260812 06:17:54.781814 25263 raft_consensus.cc:385] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:54.781860 25263 raft_consensus.cc:740] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: cac67b0310d349efaa92c24660ae28ff, State: Initialized, Role: FOLLOWER
I20260812 06:17:54.782037 25263 consensus_queue.cc:260] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff [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: "cac67b0310d349efaa92c24660ae28ff" member_type: VOTER last_known_addr { host: "127.24.124.1" port: 40659 } }
I20260812 06:17:54.782167 25263 raft_consensus.cc:399] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:54.782220 25263 raft_consensus.cc:493] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:54.782279 25263 raft_consensus.cc:3060] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:54.783103 25263 raft_consensus.cc:515] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cac67b0310d349efaa92c24660ae28ff" member_type: VOTER last_known_addr { host: "127.24.124.1" port: 40659 } }
I20260812 06:17:54.783314 25263 leader_election.cc:304] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff [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: cac67b0310d349efaa92c24660ae28ff; no voters: 
I20260812 06:17:54.783581 25263 leader_election.cc:290] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:54.783699 25265 raft_consensus.cc:2804] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:54.783965 25265 raft_consensus.cc:697] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff [term 1 LEADER]: Becoming Leader. State: Replica: cac67b0310d349efaa92c24660ae28ff, State: Running, Role: LEADER
I20260812 06:17:54.784200 25250 heartbeater.cc:499] Master 127.24.124.62:35041 was elected leader, sending a full tablet report...
I20260812 06:17:54.783973 25263 ts_tablet_manager.cc:1434] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:17:54.784770 25265 consensus_queue.cc:237] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff [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: "cac67b0310d349efaa92c24660ae28ff" member_type: VOTER last_known_addr { host: "127.24.124.1" port: 40659 } }
I20260812 06:17:54.788012 25104 catalog_manager.cc:5719] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff reported cstate change: term changed from 0 to 1, leader changed from <none> to cac67b0310d349efaa92c24660ae28ff (127.24.124.1). New cstate: current_term: 1 leader_uuid: "cac67b0310d349efaa92c24660ae28ff" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cac67b0310d349efaa92c24660ae28ff" member_type: VOTER last_known_addr { host: "127.24.124.1" port: 40659 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:54.854492 25072 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.058s	user 0.026s	sys 0.000s
I20260812 06:17:54.985987 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushMRSOp(37cde09350ec45bf99da5cb64b61a29f): perf score=15.086190
I20260812 06:17:55.148965 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushMRSOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.163s	user 0.116s	sys 0.046s Metrics: {"bytes_written":12471590,"cfile_init":1,"compiler_manager_pool.queue_time_us":226,"delete_count":0,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":214,"dirs.run_wall_time_us":2375,"drs_written":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4,"lbm_write_time_us":42914,"lbm_writes_lt_1ms":671,"mutex_wait_us":179,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":129408,"thread_start_us":160,"threads_started":1,"update_count":1520}
I20260812 06:17:55.150254 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling LogGCOp(37cde09350ec45bf99da5cb64b61a29f): free 20743880 bytes of WAL
I20260812 06:17:55.150712 25184 log_reader.cc:385] T 37cde09350ec45bf99da5cb64b61a29f: removed 2 log segments from log reader
I20260812 06:17:55.150892 25184 log.cc:1079] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/37cde09350ec45bf99da5cb64b61a29f/wal-000000001 (ops 1-6)
I20260812 06:17:55.151088 25184 log.cc:1079] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/37cde09350ec45bf99da5cb64b61a29f/wal-000000002 (ops 7-11)
I20260812 06:17:55.157204 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: LogGCOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.007s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:17:55.157732 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=2.188937
I20260812 06:17:55.177556 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.020s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3938559,"delete_count":0,"lbm_write_time_us":5863,"lbm_writes_lt_1ms":99,"reinsert_count":0,"update_count":480}
I20260812 06:17:55.178175 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling UndoDeltaBlockGCOp(37cde09350ec45bf99da5cb64b61a29f): 12719216 bytes on disk
I20260812 06:17:55.178820 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: UndoDeltaBlockGCOp(37cde09350ec45bf99da5cb64b61a29f) 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:55.179245 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=2.188937
I20260812 06:17:55.192426 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4980,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:55.193006 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling MajorDeltaCompactionOp(37cde09350ec45bf99da5cb64b61a29f): perf score=1.000000
I20260812 06:17:55.346853 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: MajorDeltaCompactionOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.154s	user 0.114s	sys 0.039s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24364554,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":963,"lbm_read_time_us":10139,"lbm_reads_lt_1ms":559,"lbm_write_time_us":31150,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":8704,"thread_start_us":346,"threads_started":5,"update_count":2450}
I20260812 06:17:55.347419 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=10.126437
I20260812 06:17:55.389861 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.042s	user 0.022s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16527,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:55.390414 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=2.188937
I20260812 06:17:55.401862 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4182,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.402359 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling MajorDeltaCompactionOp(37cde09350ec45bf99da5cb64b61a29f): perf score=1.000000
I20260812 06:17:55.540391 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: MajorDeltaCompactionOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.138s	user 0.118s	sys 0.020s 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":314,"lbm_read_time_us":9169,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27568,"lbm_writes_lt_1ms":443,"mutex_wait_us":42,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2000}
I20260812 06:17:55.541198 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=10.126437
I20260812 06:17:55.577750 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.036s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15524,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:55.578254 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=2.188937
I20260812 06:17:55.589161 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4234,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.589665 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling MajorDeltaCompactionOp(37cde09350ec45bf99da5cb64b61a29f): perf score=1.000000
I20260812 06:17:55.725952 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: MajorDeltaCompactionOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.136s	user 0.089s	sys 0.043s 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":760,"lbm_read_time_us":9367,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27901,"lbm_writes_lt_1ms":443,"mutex_wait_us":75,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":55040,"update_count":2000}
I20260812 06:17:55.726614 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=10.126437
I20260812 06:17:55.781829 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.055s	user 0.026s	sys 0.016s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15197,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:55.782522 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=2.188937
I20260812 06:17:55.794412 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.012s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4399,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.795033 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling MajorDeltaCompactionOp(37cde09350ec45bf99da5cb64b61a29f): perf score=1.000000
I20260812 06:17:55.941359 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: MajorDeltaCompactionOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.146s	user 0.114s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":662,"lbm_read_time_us":10917,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23555,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6144,"update_count":2000}
I20260812 06:17:55.941926 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=10.126437
I20260812 06:17:55.989704 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.048s	user 0.030s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16498,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:55.990170 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=2.188937
I20260812 06:17:56.001892 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4354,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.002540 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling MajorDeltaCompactionOp(37cde09350ec45bf99da5cb64b61a29f): perf score=1.000000
I20260812 06:17:56.136157 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: MajorDeltaCompactionOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.133s	user 0.117s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":306,"lbm_read_time_us":9670,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27248,"lbm_writes_lt_1ms":443,"mutex_wait_us":31,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4736,"update_count":2000}
I20260812 06:17:56.136871 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=10.126437
I20260812 06:17:56.180881 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.044s	user 0.019s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16165,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:56.181419 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=2.188937
I20260812 06:17:56.192955 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4155,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.193697 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling MajorDeltaCompactionOp(37cde09350ec45bf99da5cb64b61a29f): perf score=1.000000
I20260812 06:17:56.320137 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: MajorDeltaCompactionOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.126s	user 0.101s	sys 0.026s 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":261,"lbm_read_time_us":9231,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25184,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2000}
I20260812 06:17:56.320703 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=10.126437
I20260812 06:17:56.378480 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.058s	user 0.021s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17083,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:56.379030 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=2.188937
I20260812 06:17:56.390436 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.011s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4474,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.390987 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushMRSOp(37cde09350ec45bf99da5cb64b61a29f): perf score=1.000000
I20260812 06:17:56.452694 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushMRSOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.062s	user 0.035s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":245,"dirs.run_wall_time_us":1407,"drs_written":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1801,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:56.453645 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling LogGCOp(37cde09350ec45bf99da5cb64b61a29f): free 112239317 bytes of WAL
I20260812 06:17:56.453886 25184 log_reader.cc:385] T 37cde09350ec45bf99da5cb64b61a29f: removed 11 log segments from log reader
I20260812 06:17:56.453946 25184 log.cc:1079] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/37cde09350ec45bf99da5cb64b61a29f/wal-000000003 (ops 12-16)
I20260812 06:17:56.454006 25184 log.cc:1079] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/37cde09350ec45bf99da5cb64b61a29f/wal-000000004 (ops 17-21)
I20260812 06:17:56.454046 25184 log.cc:1079] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/37cde09350ec45bf99da5cb64b61a29f/wal-000000005 (ops 22-26)
I20260812 06:17:56.454100 25184 log.cc:1079] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/37cde09350ec45bf99da5cb64b61a29f/wal-000000006 (ops 27-31)
I20260812 06:17:56.454141 25184 log.cc:1079] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/37cde09350ec45bf99da5cb64b61a29f/wal-000000007 (ops 32-36)
I20260812 06:17:56.454183 25184 log.cc:1079] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/37cde09350ec45bf99da5cb64b61a29f/wal-000000008 (ops 37-40)
I20260812 06:17:56.454226 25184 log.cc:1079] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/37cde09350ec45bf99da5cb64b61a29f/wal-000000009 (ops 41-45)
I20260812 06:17:56.454268 25184 log.cc:1079] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/37cde09350ec45bf99da5cb64b61a29f/wal-000000010 (ops 46-50)
I20260812 06:17:56.454310 25184 log.cc:1079] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/37cde09350ec45bf99da5cb64b61a29f/wal-000000011 (ops 51-55)
I20260812 06:17:56.454352 25184 log.cc:1079] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/37cde09350ec45bf99da5cb64b61a29f/wal-000000012 (ops 56-60)
I20260812 06:17:56.454394 25184 log.cc:1079] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/37cde09350ec45bf99da5cb64b61a29f/wal-000000013 (ops 61-65)
I20260812 06:17:56.477710 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: LogGCOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.024s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:17:56.478188 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling UndoDeltaBlockGCOp(37cde09350ec45bf99da5cb64b61a29f): 447 bytes on disk
I20260812 06:17:56.478866 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: UndoDeltaBlockGCOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":98,"lbm_reads_lt_1ms":4}
I20260812 06:17:56.479341 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=2.188937
I20260812 06:17:56.493165 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5213,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.493721 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling MajorDeltaCompactionOp(37cde09350ec45bf99da5cb64b61a29f): perf score=1.000000
I20260812 06:17:56.740864 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: MajorDeltaCompactionOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.247s	user 0.165s	sys 0.081s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774808,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1734,"lbm_read_time_us":11142,"lbm_reads_lt_1ms":569,"lbm_write_time_us":42490,"lbm_writes_lt_1ms":543,"mutex_wait_us":58,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19968,"thread_start_us":89,"threads_started":1,"update_count":2500}
I20260812 06:17:56.741561 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=18.063937
I20260812 06:17:56.824318 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.082s	user 0.051s	sys 0.028s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":35642,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:56.824963 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=2.188937
I20260812 06:17:56.844367 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.019s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7160,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.844959 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=2.188937
I20260812 06:17:56.863837 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.019s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7199,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.864392 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling MajorDeltaCompactionOp(37cde09350ec45bf99da5cb64b61a29f): perf score=1.000000
I20260812 06:17:57.111105 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: MajorDeltaCompactionOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.247s	user 0.189s	sys 0.053s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979634,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":198,"lbm_read_time_us":18971,"lbm_reads_lt_1ms":765,"lbm_write_time_us":43579,"lbm_writes_lt_1ms":743,"mutex_wait_us":41,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":8576,"update_count":3500}
I20260812 06:17:57.111730 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=18.063937
I20260812 06:17:57.175915 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.064s	user 0.042s	sys 0.019s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":28890,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:57.176574 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=2.188937
I20260812 06:17:57.190594 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5206,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.191126 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling MajorDeltaCompactionOp(37cde09350ec45bf99da5cb64b61a29f): perf score=1.000000
I20260812 06:17:57.365211 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: MajorDeltaCompactionOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.174s	user 0.138s	sys 0.036s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":279,"lbm_read_time_us":11183,"lbm_reads_lt_1ms":672,"lbm_write_time_us":39323,"lbm_writes_lt_1ms":643,"mutex_wait_us":25,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12416,"update_count":3000}
I20260812 06:17:57.365976 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=14.095187
I20260812 06:17:57.414867 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.049s	user 0.044s	sys 0.003s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21439,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:57.415589 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=2.188937
I20260812 06:17:57.431169 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5735,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.431753 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling MajorDeltaCompactionOp(37cde09350ec45bf99da5cb64b61a29f): perf score=1.000000
I20260812 06:17:57.584514 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: MajorDeltaCompactionOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.153s	user 0.123s	sys 0.029s 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":524,"lbm_read_time_us":8906,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29331,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":2500}
I20260812 06:17:57.585232 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=14.095187
I20260812 06:17:57.651257 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.066s	user 0.046s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25952,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:57.651827 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=2.188937
I20260812 06:17:57.663625 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.012s	user 0.001s	sys 0.008s 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:57.664156 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling MajorDeltaCompactionOp(37cde09350ec45bf99da5cb64b61a29f): perf score=1.000000
I20260812 06:17:57.836938 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: MajorDeltaCompactionOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.173s	user 0.094s	sys 0.072s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":271,"lbm_read_time_us":12233,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29796,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":28032,"update_count":2500}
I20260812 06:17:57.837689 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=14.095187
I20260812 06:17:57.893996 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.054s	user 0.024s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19588,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:57.894543 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=2.188937
I20260812 06:17:57.905377 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4150,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.906035 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushMRSOp(37cde09350ec45bf99da5cb64b61a29f): perf score=1.000000
I20260812 06:17:57.949203 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushMRSOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.043s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":138,"dirs.run_wall_time_us":1418,"drs_written":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1555,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:57.950070 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling LogGCOp(37cde09350ec45bf99da5cb64b61a29f): free 120553331 bytes of WAL
I20260812 06:17:57.950332 25184 log_reader.cc:385] T 37cde09350ec45bf99da5cb64b61a29f: removed 12 log segments from log reader
I20260812 06:17:57.950402 25184 log.cc:1079] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/37cde09350ec45bf99da5cb64b61a29f/wal-000000014 (ops 66-70)
I20260812 06:17:57.950450 25184 log.cc:1079] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/37cde09350ec45bf99da5cb64b61a29f/wal-000000015 (ops 71-74)
I20260812 06:17:57.950495 25184 log.cc:1079] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/37cde09350ec45bf99da5cb64b61a29f/wal-000000016 (ops 75-79)
I20260812 06:17:57.950551 25184 log.cc:1079] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/37cde09350ec45bf99da5cb64b61a29f/wal-000000017 (ops 80-84)
I20260812 06:17:57.950589 25184 log.cc:1079] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/37cde09350ec45bf99da5cb64b61a29f/wal-000000018 (ops 85-89)
I20260812 06:17:57.950624 25184 log.cc:1079] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/37cde09350ec45bf99da5cb64b61a29f/wal-000000019 (ops 90-94)
I20260812 06:17:57.950661 25184 log.cc:1079] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/37cde09350ec45bf99da5cb64b61a29f/wal-000000020 (ops 95-99)
I20260812 06:17:57.950737 25184 log.cc:1079] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/37cde09350ec45bf99da5cb64b61a29f/wal-000000021 (ops 100-104)
I20260812 06:17:57.950774 25184 log.cc:1079] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/37cde09350ec45bf99da5cb64b61a29f/wal-000000022 (ops 105-109)
I20260812 06:17:57.950819 25184 log.cc:1079] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/37cde09350ec45bf99da5cb64b61a29f/wal-000000023 (ops 110-114)
I20260812 06:17:57.950865 25184 log.cc:1079] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/37cde09350ec45bf99da5cb64b61a29f/wal-000000024 (ops 115-118)
I20260812 06:17:57.950908 25184 log.cc:1079] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/37cde09350ec45bf99da5cb64b61a29f/wal-000000025 (ops 119-123)
I20260812 06:17:57.977420 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: LogGCOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.027s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:17:57.978066 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling UndoDeltaBlockGCOp(37cde09350ec45bf99da5cb64b61a29f): 463 bytes on disk
I20260812 06:17:57.978556 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: UndoDeltaBlockGCOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4}
I20260812 06:17:57.979251 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=2.188937
I20260812 06:17:57.993891 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.014s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4225735,"delete_count":0,"lbm_write_time_us":4499,"lbm_writes_lt_1ms":106,"reinsert_count":0,"update_count":515}
I20260812 06:17:57.994313 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=2.188937
I20260812 06:17:58.004738 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3979583,"delete_count":0,"lbm_write_time_us":4049,"lbm_writes_lt_1ms":100,"reinsert_count":0,"update_count":485}
I20260812 06:17:58.005180 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling MajorDeltaCompactionOp(37cde09350ec45bf99da5cb64b61a29f): perf score=1.000000
I20260812 06:17:58.235766 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: MajorDeltaCompactionOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.230s	user 0.138s	sys 0.080s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979750,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":602,"lbm_read_time_us":15290,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39026,"lbm_writes_lt_1ms":743,"mutex_wait_us":70,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1536,"thread_start_us":78,"threads_started":1,"update_count":3500}
I20260812 06:17:58.236552 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=18.063937
I20260812 06:17:58.292496 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.056s	user 0.027s	sys 0.021s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":23245,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:58.293087 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=2.188937
I20260812 06:17:58.305631 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4285,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:58.306177 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling MajorDeltaCompactionOp(37cde09350ec45bf99da5cb64b61a29f): perf score=1.000000
I20260812 06:17:58.470620 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: MajorDeltaCompactionOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.164s	user 0.125s	sys 0.039s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":171,"lbm_read_time_us":11499,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33471,"lbm_writes_lt_1ms":643,"mutex_wait_us":41,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":3000}
I20260812 06:17:58.471267 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=14.095187
I20260812 06:17:58.517802 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.046s	user 0.013s	sys 0.033s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21086,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:58.518378 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=2.188937
I20260812 06:17:58.530153 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.011s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4317,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:58.530790 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling MajorDeltaCompactionOp(37cde09350ec45bf99da5cb64b61a29f): perf score=1.000000
I20260812 06:17:58.714140 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: MajorDeltaCompactionOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.183s	user 0.104s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":161,"lbm_read_time_us":11938,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35153,"lbm_writes_lt_1ms":543,"mutex_wait_us":72,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":29696,"update_count":2500}
I20260812 06:17:58.714901 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=14.095187
I20260812 06:17:58.769258 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.054s	user 0.037s	sys 0.009s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22309,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:58.769877 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling MajorDeltaCompactionOp(37cde09350ec45bf99da5cb64b61a29f): perf score=1.000000
I20260812 06:17:58.923769 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: MajorDeltaCompactionOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.154s	user 0.121s	sys 0.025s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":285,"lbm_read_time_us":10184,"lbm_reads_lt_1ms":463,"lbm_write_time_us":23752,"lbm_writes_lt_1ms":443,"mutex_wait_us":107,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:58.924468 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=14.095187
I20260812 06:17:58.976432 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.052s	user 0.029s	sys 0.016s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21226,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:58.977023 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=2.188937
I20260812 06:17:58.988940 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4143,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:58.989696 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling MajorDeltaCompactionOp(37cde09350ec45bf99da5cb64b61a29f): perf score=1.000000
I20260812 06:17:59.191072 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: MajorDeltaCompactionOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.201s	user 0.119s	sys 0.068s 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":238,"lbm_read_time_us":12502,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32616,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13440,"update_count":2500}
I20260812 06:17:59.191628 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=14.095187
I20260812 06:17:59.245883 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.054s	user 0.023s	sys 0.025s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21083,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:59.246470 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=2.188937
I20260812 06:17:59.259109 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.012s	user 0.009s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4231,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:59.259804 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling MajorDeltaCompactionOp(37cde09350ec45bf99da5cb64b61a29f): perf score=1.000000
I20260812 06:17:59.441943 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: MajorDeltaCompactionOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.182s	user 0.142s	sys 0.028s 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":113,"lbm_read_time_us":10467,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35409,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":2500}
I20260812 06:17:59.442703 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=14.095187
I20260812 06:17:59.502056 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.059s	user 0.045s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25101,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:59.502792 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=2.188937
I20260812 06:17:59.520712 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.018s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5580,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:59.521409 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushMRSOp(37cde09350ec45bf99da5cb64b61a29f): perf score=1.000000
I20260812 06:17:59.562476 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushMRSOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.041s	user 0.038s	sys 0.001s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":86,"dirs.run_cpu_time_us":251,"dirs.run_wall_time_us":1580,"drs_written":1,"lbm_read_time_us":126,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1846,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:59.563678 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling LogGCOp(37cde09350ec45bf99da5cb64b61a29f): free 136728553 bytes of WAL
I20260812 06:17:59.564008 25184 log_reader.cc:385] T 37cde09350ec45bf99da5cb64b61a29f: removed 13 log segments from log reader
I20260812 06:17:59.564123 25184 log.cc:1079] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/37cde09350ec45bf99da5cb64b61a29f/wal-000000026 (ops 124-128)
I20260812 06:17:59.564186 25184 log.cc:1079] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/37cde09350ec45bf99da5cb64b61a29f/wal-000000027 (ops 129-133)
I20260812 06:17:59.564244 25184 log.cc:1079] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/37cde09350ec45bf99da5cb64b61a29f/wal-000000028 (ops 134-138)
I20260812 06:17:59.564286 25184 log.cc:1079] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/37cde09350ec45bf99da5cb64b61a29f/wal-000000029 (ops 139-143)
I20260812 06:17:59.564322 25184 log.cc:1079] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/37cde09350ec45bf99da5cb64b61a29f/wal-000000030 (ops 144-148)
I20260812 06:17:59.564361 25184 log.cc:1079] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/37cde09350ec45bf99da5cb64b61a29f/wal-000000031 (ops 149-153)
I20260812 06:17:59.564397 25184 log.cc:1079] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/37cde09350ec45bf99da5cb64b61a29f/wal-000000032 (ops 154-158)
I20260812 06:17:59.564435 25184 log.cc:1079] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/37cde09350ec45bf99da5cb64b61a29f/wal-000000033 (ops 159-163)
I20260812 06:17:59.564471 25184 log.cc:1079] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/37cde09350ec45bf99da5cb64b61a29f/wal-000000034 (ops 164-168)
I20260812 06:17:59.564508 25184 log.cc:1079] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/37cde09350ec45bf99da5cb64b61a29f/wal-000000035 (ops 169-173)
I20260812 06:17:59.564544 25184 log.cc:1079] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/37cde09350ec45bf99da5cb64b61a29f/wal-000000036 (ops 174-178)
I20260812 06:17:59.564590 25184 log.cc:1079] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/37cde09350ec45bf99da5cb64b61a29f/wal-000000037 (ops 179-183)
I20260812 06:17:59.564626 25184 log.cc:1079] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/37cde09350ec45bf99da5cb64b61a29f/wal-000000038 (ops 184-188)
I20260812 06:17:59.597209 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: LogGCOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.033s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:17:59.598023 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=5.165500
I20260812 06:17:59.631320 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.033s	user 0.015s	sys 0.016s Metrics: {"bytes_written":6851279,"delete_count":0,"lbm_write_time_us":8901,"lbm_writes_lt_1ms":170,"reinsert_count":0,"update_count":835}
I20260812 06:17:59.631980 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=1.000000
I20260812 06:17:59.640964 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.009s	user 0.006s	sys 0.000s Metrics: {"bytes_written":1353977,"delete_count":0,"lbm_write_time_us":2373,"lbm_writes_lt_1ms":36,"reinsert_count":0,"update_count":165}
I20260812 06:17:59.641520 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling UndoDeltaBlockGCOp(37cde09350ec45bf99da5cb64b61a29f): 492 bytes on disk
I20260812 06:17:59.642210 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: UndoDeltaBlockGCOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":95,"lbm_reads_lt_1ms":4}
I20260812 06:17:59.642845 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling MajorDeltaCompactionOp(37cde09350ec45bf99da5cb64b61a29f): perf score=1.000000
I20260812 06:17:59.874312 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: MajorDeltaCompactionOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.231s	user 0.133s	sys 0.097s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2252,"lbm_read_time_us":15450,"lbm_reads_lt_1ms":774,"lbm_write_time_us":42012,"lbm_writes_lt_1ms":743,"mutex_wait_us":103,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":14976,"thread_start_us":80,"threads_started":1,"update_count":3500}
I20260812 06:17:59.875458 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=14.095187
I20260812 06:17:59.918725 25072 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.064s	user 1.899s	sys 0.130s
I20260812 06:17:59.924567 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.049s	user 0.037s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23123,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:59.925055 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f): perf score=2.188937
I20260812 06:17:59.937331 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: FlushDeltaMemStoresOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4973,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:59.937834 25251 maintenance_manager.cc:419] P cac67b0310d349efaa92c24660ae28ff: Scheduling MajorDeltaCompactionOp(37cde09350ec45bf99da5cb64b61a29f): perf score=1.000000
I20260812 06:17:59.970855 25072 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.052s	user 0.003s	sys 0.000s
I20260812 06:17:59.971542 25072 tablet_server.cc:179] TabletServer@127.24.124.1:0 shutting down...
I20260812 06:18:00.084420 25184 maintenance_manager.cc:643] P cac67b0310d349efaa92c24660ae28ff: MajorDeltaCompactionOp(37cde09350ec45bf99da5cb64b61a29f) complete. Timing: real 0.146s	user 0.105s	sys 0.041s Metrics: {"cfile_cache_hit":30,"cfile_cache_hit_bytes":4262390,"cfile_cache_miss":502,"cfile_cache_miss_bytes":20512298,"cfile_init":4,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":327,"lbm_read_time_us":8066,"lbm_reads_lt_1ms":518,"lbm_write_time_us":25417,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":22656,"update_count":2500}
I20260812 06:18:00.085358 25072 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:00.085781 25072 tablet_replica.cc:333] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff: stopping tablet replica
I20260812 06:18:00.086035 25072 raft_consensus.cc:2243] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:00.086292 25072 raft_consensus.cc:2272] T 37cde09350ec45bf99da5cb64b61a29f P cac67b0310d349efaa92c24660ae28ff [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:00.101955 25072 tablet_server.cc:196] TabletServer@127.24.124.1:0 shutdown complete.
I20260812 06:18:00.130913 25072 master.cc:562] Master@127.24.124.62:35041 shutting down...
I20260812 06:18:00.135354 25072 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 19600b197ccb485c8185f0d8034f54e7 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:00.135584 25072 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 19600b197ccb485c8185f0d8034f54e7 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:00.135691 25072 tablet_replica.cc:333] T 00000000000000000000000000000000 P 19600b197ccb485c8185f0d8034f54e7: stopping tablet replica
I20260812 06:18:00.149444 25072 master.cc:584] Master@127.24.124.62:35041 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5680 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:00.239933 25072 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.24.124.62:39491
I20260812 06:18:00.240288 25072 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:00.242410 25287 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:00.242504 25288 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:00.242596 25072 server_base.cc:1061] running on GCE node
W20260812 06:18:00.242544 25290 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:00.242944 25072 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:00.243007 25072 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:00.243031 25072 hybrid_clock.cc:648] HybridClock initialized: now 1786515480243030 us; error 0 us; skew 500 ppm
I20260812 06:18:00.243897 25072 webserver.cc:533] Webserver started at http://127.24.124.62:42839/ using document root <none> and password file <none>
I20260812 06:18:00.244104 25072 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:00.244181 25072 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:00.244266 25072 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:00.244702 25072 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/master-0-root/instance:
uuid: "fe9bef8370314a9eafd77882896ee41a"
format_stamp: "Formatted at 2026-08-12 06:18:00 on dist-test-slave-njxd"
I20260812 06:18:00.246364 25072 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:00.247404 25296 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:00.247691 25072 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:00.247793 25072 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/master-0-root
uuid: "fe9bef8370314a9eafd77882896ee41a"
format_stamp: "Formatted at 2026-08-12 06:18:00 on dist-test-slave-njxd"
I20260812 06:18:00.247890 25072 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:00.269856 25072 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:00.270339 25072 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:00.274756 25072 rpc_server.cc:307] RPC server started. Bound to: 127.24.124.62:39491
I20260812 06:18:00.277468 25357 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.124.62:39491 every 8 connection(s)
I20260812 06:18:00.279937 25358 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:00.290750 25358 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P fe9bef8370314a9eafd77882896ee41a: Bootstrap starting.
I20260812 06:18:00.291615 25358 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P fe9bef8370314a9eafd77882896ee41a: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:00.292825 25358 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P fe9bef8370314a9eafd77882896ee41a: No bootstrap required, opened a new log
I20260812 06:18:00.293234 25358 raft_consensus.cc:359] T 00000000000000000000000000000000 P fe9bef8370314a9eafd77882896ee41a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fe9bef8370314a9eafd77882896ee41a" member_type: VOTER }
I20260812 06:18:00.293329 25358 raft_consensus.cc:385] T 00000000000000000000000000000000 P fe9bef8370314a9eafd77882896ee41a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:00.293351 25358 raft_consensus.cc:740] T 00000000000000000000000000000000 P fe9bef8370314a9eafd77882896ee41a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: fe9bef8370314a9eafd77882896ee41a, State: Initialized, Role: FOLLOWER
I20260812 06:18:00.293476 25358 consensus_queue.cc:260] T 00000000000000000000000000000000 P fe9bef8370314a9eafd77882896ee41a [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: "fe9bef8370314a9eafd77882896ee41a" member_type: VOTER }
I20260812 06:18:00.293535 25358 raft_consensus.cc:399] T 00000000000000000000000000000000 P fe9bef8370314a9eafd77882896ee41a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:00.293557 25358 raft_consensus.cc:493] T 00000000000000000000000000000000 P fe9bef8370314a9eafd77882896ee41a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:00.293716 25358 raft_consensus.cc:3060] T 00000000000000000000000000000000 P fe9bef8370314a9eafd77882896ee41a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:00.294574 25358 raft_consensus.cc:515] T 00000000000000000000000000000000 P fe9bef8370314a9eafd77882896ee41a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fe9bef8370314a9eafd77882896ee41a" member_type: VOTER }
I20260812 06:18:00.294725 25358 leader_election.cc:304] T 00000000000000000000000000000000 P fe9bef8370314a9eafd77882896ee41a [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: fe9bef8370314a9eafd77882896ee41a; no voters: 
I20260812 06:18:00.294902 25358 leader_election.cc:290] T 00000000000000000000000000000000 P fe9bef8370314a9eafd77882896ee41a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:00.295065 25361 raft_consensus.cc:2804] T 00000000000000000000000000000000 P fe9bef8370314a9eafd77882896ee41a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:00.295352 25361 raft_consensus.cc:697] T 00000000000000000000000000000000 P fe9bef8370314a9eafd77882896ee41a [term 1 LEADER]: Becoming Leader. State: Replica: fe9bef8370314a9eafd77882896ee41a, State: Running, Role: LEADER
I20260812 06:18:00.295439 25358 sys_catalog.cc:565] T 00000000000000000000000000000000 P fe9bef8370314a9eafd77882896ee41a [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:00.295511 25361 consensus_queue.cc:237] T 00000000000000000000000000000000 P fe9bef8370314a9eafd77882896ee41a [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: "fe9bef8370314a9eafd77882896ee41a" member_type: VOTER }
I20260812 06:18:00.295996 25364 sys_catalog.cc:455] T 00000000000000000000000000000000 P fe9bef8370314a9eafd77882896ee41a [sys.catalog]: SysCatalogTable state changed. Reason: New leader fe9bef8370314a9eafd77882896ee41a. Latest consensus state: current_term: 1 leader_uuid: "fe9bef8370314a9eafd77882896ee41a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fe9bef8370314a9eafd77882896ee41a" member_type: VOTER } }
I20260812 06:18:00.295977 25363 sys_catalog.cc:455] T 00000000000000000000000000000000 P fe9bef8370314a9eafd77882896ee41a [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "fe9bef8370314a9eafd77882896ee41a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fe9bef8370314a9eafd77882896ee41a" member_type: VOTER } }
I20260812 06:18:00.296123 25364 sys_catalog.cc:458] T 00000000000000000000000000000000 P fe9bef8370314a9eafd77882896ee41a [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:00.296190 25363 sys_catalog.cc:458] T 00000000000000000000000000000000 P fe9bef8370314a9eafd77882896ee41a [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:00.296803 25370 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:00.297652 25370 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:00.297891 25072 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:00.299546 25370 catalog_manager.cc:1383] Generated new cluster ID: 1153949d1130478a9b7f8d7da2c278ad
I20260812 06:18:00.299609 25370 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:00.319526 25370 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:00.320104 25370 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:00.334355 25370 catalog_manager.cc:6092] T 00000000000000000000000000000000 P fe9bef8370314a9eafd77882896ee41a: Generated new TSK 0
I20260812 06:18:00.334573 25370 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:00.362784 25072 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:00.364861 25383 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:00.364926 25384 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:00.364861 25386 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:00.365109 25072 server_base.cc:1061] running on GCE node
I20260812 06:18:00.365398 25072 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:00.365442 25072 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:00.365458 25072 hybrid_clock.cc:648] HybridClock initialized: now 1786515480365458 us; error 0 us; skew 500 ppm
I20260812 06:18:00.366377 25072 webserver.cc:533] Webserver started at http://127.24.124.1:46151/ using document root <none> and password file <none>
I20260812 06:18:00.366520 25072 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:00.366564 25072 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:00.366624 25072 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:00.367060 25072 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root/instance:
uuid: "e521c9c8251543b6853ad08cfca6f5d8"
format_stamp: "Formatted at 2026-08-12 06:18:00 on dist-test-slave-njxd"
I20260812 06:18:00.368635 25072 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:00.369740 25391 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:00.370064 25072 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:00.370138 25072 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root
uuid: "e521c9c8251543b6853ad08cfca6f5d8"
format_stamp: "Formatted at 2026-08-12 06:18:00 on dist-test-slave-njxd"
I20260812 06:18:00.370200 25072 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:00.386189 25072 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:00.386564 25072 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:00.386852 25072 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:00.387379 25072 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:00.387418 25072 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:00.387486 25072 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:00.387527 25072 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:00.392306 25072 rpc_server.cc:307] RPC server started. Bound to: 127.24.124.1:46043
I20260812 06:18:00.393154 25461 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.124.1:46043 every 8 connection(s)
I20260812 06:18:00.402263 25462 heartbeater.cc:344] Connected to a master server at 127.24.124.62:39491
I20260812 06:18:00.402402 25462 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:00.402688 25462 heartbeater.cc:507] Master 127.24.124.62:39491 requested a full tablet report, sending...
I20260812 06:18:00.403404 25316 ts_manager.cc:194] Registered new tserver with Master: e521c9c8251543b6853ad08cfca6f5d8 (127.24.124.1:46043)
I20260812 06:18:00.404168 25316 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:41100
I20260812 06:18:00.404409 25072 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011195906s
I20260812 06:18:00.411906 25316 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:41116:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:00.421324 25420 tablet_service.cc:1511] Processing CreateTablet for tablet 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 (DEFAULT_TABLE table=heavy-update-compaction-test [id=2c07bdc76ecc4fd788218b9fc9332e16]), partition=
I20260812 06:18:00.421715 25420 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 8e1f2e7a4a6248d2a4ecaad6b1d5bda1. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:00.423749 25476 tablet_bootstrap.cc:492] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Bootstrap starting.
I20260812 06:18:00.424731 25476 tablet_bootstrap.cc:654] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:00.426050 25476 tablet_bootstrap.cc:492] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: No bootstrap required, opened a new log
I20260812 06:18:00.426172 25476 ts_tablet_manager.cc:1403] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:00.426651 25476 raft_consensus.cc:359] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e521c9c8251543b6853ad08cfca6f5d8" member_type: VOTER last_known_addr { host: "127.24.124.1" port: 46043 } }
I20260812 06:18:00.426751 25476 raft_consensus.cc:385] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:00.426775 25476 raft_consensus.cc:740] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e521c9c8251543b6853ad08cfca6f5d8, State: Initialized, Role: FOLLOWER
I20260812 06:18:00.426925 25476 consensus_queue.cc:260] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8 [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: "e521c9c8251543b6853ad08cfca6f5d8" member_type: VOTER last_known_addr { host: "127.24.124.1" port: 46043 } }
I20260812 06:18:00.427052 25476 raft_consensus.cc:399] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:00.427088 25476 raft_consensus.cc:493] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:00.427150 25476 raft_consensus.cc:3060] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:00.428021 25476 raft_consensus.cc:515] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e521c9c8251543b6853ad08cfca6f5d8" member_type: VOTER last_known_addr { host: "127.24.124.1" port: 46043 } }
I20260812 06:18:00.428160 25476 leader_election.cc:304] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8 [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: e521c9c8251543b6853ad08cfca6f5d8; no voters: 
I20260812 06:18:00.428333 25476 leader_election.cc:290] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:00.428488 25478 raft_consensus.cc:2804] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:00.428706 25476 ts_tablet_manager.cc:1434] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:18:00.428731 25462 heartbeater.cc:499] Master 127.24.124.62:39491 was elected leader, sending a full tablet report...
I20260812 06:18:00.428798 25478 raft_consensus.cc:697] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8 [term 1 LEADER]: Becoming Leader. State: Replica: e521c9c8251543b6853ad08cfca6f5d8, State: Running, Role: LEADER
I20260812 06:18:00.428966 25478 consensus_queue.cc:237] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8 [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: "e521c9c8251543b6853ad08cfca6f5d8" member_type: VOTER last_known_addr { host: "127.24.124.1" port: 46043 } }
I20260812 06:18:00.430474 25316 catalog_manager.cc:5719] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8 reported cstate change: term changed from 0 to 1, leader changed from <none> to e521c9c8251543b6853ad08cfca6f5d8 (127.24.124.1). New cstate: current_term: 1 leader_uuid: "e521c9c8251543b6853ad08cfca6f5d8" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e521c9c8251543b6853ad08cfca6f5d8" member_type: VOTER last_known_addr { host: "127.24.124.1" port: 46043 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:00.492178 25072 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.014s	sys 0.009s
I20260812 06:18:00.643759 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushMRSOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=19.054940
I20260812 06:18:00.807917 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushMRSOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.164s	user 0.112s	sys 0.048s Metrics: {"bytes_written":12307491,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":81,"dirs.run_cpu_time_us":228,"dirs.run_wall_time_us":932,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41930,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:18:00.808607 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling LogGCOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): free 20743880 bytes of WAL
I20260812 06:18:00.808859 25396 log_reader.cc:385] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1: removed 2 log segments from log reader
I20260812 06:18:00.808908 25396 log.cc:1079] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/8e1f2e7a4a6248d2a4ecaad6b1d5bda1/wal-000000001 (ops 1-6)
I20260812 06:18:00.808939 25396 log.cc:1079] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/8e1f2e7a4a6248d2a4ecaad6b1d5bda1/wal-000000002 (ops 7-11)
I20260812 06:18:00.813328 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: LogGCOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:18:00.813798 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling UndoDeltaBlockGCOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): 16411393 bytes on disk
I20260812 06:18:00.814277 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: UndoDeltaBlockGCOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:18:00.814731 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=2.188937
I20260812 06:18:00.831821 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.017s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6064,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:00.832403 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling MajorDeltaCompactionOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=1.000000
I20260812 06:18:00.979539 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: MajorDeltaCompactionOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.147s	user 0.103s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1343,"lbm_read_time_us":9625,"lbm_reads_lt_1ms":460,"lbm_write_time_us":25296,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":602,"threads_started":5,"update_count":2000}
I20260812 06:18:00.980159 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=14.095187
I20260812 06:18:01.033485 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.053s	user 0.036s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23031,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:01.033998 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=2.188937
I20260812 06:18:01.045488 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4237,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:01.046032 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling MajorDeltaCompactionOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=1.000000
I20260812 06:18:01.205649 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: MajorDeltaCompactionOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.159s	user 0.119s	sys 0.039s 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":457,"lbm_read_time_us":11949,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28961,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:18:01.206902 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=12.110812
I20260812 06:18:01.240891 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.034s	user 0.022s	sys 0.008s Metrics: {"bytes_written":13538207,"delete_count":0,"lbm_write_time_us":13979,"lbm_writes_lt_1ms":333,"reinsert_count":0,"update_count":1650}
I20260812 06:18:01.241511 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=1.196750
I20260812 06:18:01.267459 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.025s	user 0.006s	sys 0.005s Metrics: {"bytes_written":2871905,"delete_count":0,"lbm_write_time_us":5858,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":72,"reinsert_count":0,"update_count":350}
I20260812 06:18:01.267970 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=2.188937
I20260812 06:18:01.279544 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.011s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4636,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:01.280184 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling MajorDeltaCompactionOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=1.000000
I20260812 06:18:01.462742 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: MajorDeltaCompactionOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.182s	user 0.122s	sys 0.060s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774770,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":782,"lbm_read_time_us":12461,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31541,"lbm_writes_lt_1ms":543,"mutex_wait_us":333,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":2500}
I20260812 06:18:01.463259 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=14.095187
I20260812 06:18:01.522784 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.059s	user 0.023s	sys 0.028s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23630,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:01.523237 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=2.188937
I20260812 06:18:01.534112 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4042,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:01.534663 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling MajorDeltaCompactionOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=1.000000
I20260812 06:18:01.726910 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: MajorDeltaCompactionOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.192s	user 0.135s	sys 0.055s 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":855,"lbm_read_time_us":13942,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30445,"lbm_writes_lt_1ms":543,"mutex_wait_us":238,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":40192,"update_count":2500}
I20260812 06:18:01.727725 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=14.095187
I20260812 06:18:01.793152 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.065s	user 0.030s	sys 0.031s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23655,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:01.793890 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=2.188937
I20260812 06:18:01.805464 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4358,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:01.806083 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling MajorDeltaCompactionOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=1.000000
I20260812 06:18:01.993167 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: MajorDeltaCompactionOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.187s	user 0.113s	sys 0.064s 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":843,"lbm_read_time_us":13761,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28096,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14592,"update_count":2500}
I20260812 06:18:01.994000 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=14.095187
I20260812 06:18:02.051755 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.057s	user 0.025s	sys 0.024s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":19781,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:02.052402 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=2.188937
I20260812 06:18:02.063351 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4280,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:02.063866 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushMRSOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=1.000000
I20260812 06:18:02.107363 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushMRSOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.043s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":208,"dirs.run_wall_time_us":1630,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1654,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:02.108017 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling LogGCOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): free 120100332 bytes of WAL
I20260812 06:18:02.108255 25396 log_reader.cc:385] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1: removed 12 log segments from log reader
I20260812 06:18:02.108304 25396 log.cc:1079] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/8e1f2e7a4a6248d2a4ecaad6b1d5bda1/wal-000000003 (ops 12-16)
I20260812 06:18:02.108336 25396 log.cc:1079] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/8e1f2e7a4a6248d2a4ecaad6b1d5bda1/wal-000000004 (ops 17-21)
I20260812 06:18:02.108400 25396 log.cc:1079] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/8e1f2e7a4a6248d2a4ecaad6b1d5bda1/wal-000000005 (ops 22-26)
I20260812 06:18:02.108430 25396 log.cc:1079] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/8e1f2e7a4a6248d2a4ecaad6b1d5bda1/wal-000000006 (ops 27-31)
I20260812 06:18:02.108469 25396 log.cc:1079] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/8e1f2e7a4a6248d2a4ecaad6b1d5bda1/wal-000000007 (ops 32-36)
I20260812 06:18:02.108508 25396 log.cc:1079] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/8e1f2e7a4a6248d2a4ecaad6b1d5bda1/wal-000000008 (ops 37-40)
I20260812 06:18:02.108546 25396 log.cc:1079] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/8e1f2e7a4a6248d2a4ecaad6b1d5bda1/wal-000000009 (ops 41-45)
I20260812 06:18:02.108582 25396 log.cc:1079] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/8e1f2e7a4a6248d2a4ecaad6b1d5bda1/wal-000000010 (ops 46-50)
I20260812 06:18:02.108620 25396 log.cc:1079] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/8e1f2e7a4a6248d2a4ecaad6b1d5bda1/wal-000000011 (ops 51-54)
I20260812 06:18:02.108657 25396 log.cc:1079] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/8e1f2e7a4a6248d2a4ecaad6b1d5bda1/wal-000000012 (ops 55-59)
I20260812 06:18:02.108695 25396 log.cc:1079] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/8e1f2e7a4a6248d2a4ecaad6b1d5bda1/wal-000000013 (ops 60-64)
I20260812 06:18:02.108731 25396 log.cc:1079] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/8e1f2e7a4a6248d2a4ecaad6b1d5bda1/wal-000000014 (ops 65-68)
I20260812 06:18:02.135720 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: LogGCOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:18:02.136219 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling UndoDeltaBlockGCOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): 463 bytes on disk
I20260812 06:18:02.136687 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: UndoDeltaBlockGCOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) 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:18:02.137202 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=3.181125
I20260812 06:18:02.155205 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.018s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4549,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:02.155761 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=2.188937
I20260812 06:18:02.168809 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.013s	user 0.008s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5180,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:02.169317 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling MajorDeltaCompactionOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=1.000000
I20260812 06:18:02.412568 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: MajorDeltaCompactionOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.243s	user 0.183s	sys 0.056s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979740,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":515,"lbm_read_time_us":17144,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41091,"lbm_writes_lt_1ms":743,"mutex_wait_us":75,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1408,"thread_start_us":85,"threads_started":1,"update_count":3500}
I20260812 06:18:02.413316 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=18.063937
I20260812 06:18:02.482604 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.069s	user 0.045s	sys 0.023s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":31434,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:18:02.483521 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=2.188937
I20260812 06:18:02.511827 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.028s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5835,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:02.512318 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=2.188937
I20260812 06:18:02.523276 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4059,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:02.523793 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling MajorDeltaCompactionOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=1.000000
I20260812 06:18:02.725884 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: MajorDeltaCompactionOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.202s	user 0.153s	sys 0.047s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979635,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1637,"lbm_read_time_us":14126,"lbm_reads_lt_1ms":773,"lbm_write_time_us":42950,"lbm_writes_lt_1ms":743,"mutex_wait_us":269,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":26112,"update_count":3500}
I20260812 06:18:02.726744 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=14.095187
I20260812 06:18:02.774269 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.047s	user 0.029s	sys 0.017s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20859,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:02.775194 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=2.188937
I20260812 06:18:02.792186 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.017s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5833,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:02.792793 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling MajorDeltaCompactionOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=1.000000
I20260812 06:18:02.932807 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: MajorDeltaCompactionOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.140s	user 0.117s	sys 0.021s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1091,"lbm_read_time_us":9866,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27478,"lbm_writes_lt_1ms":543,"mutex_wait_us":371,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":2500}
I20260812 06:18:02.933705 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=14.095187
I20260812 06:18:02.985194 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.051s	user 0.037s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21339,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:02.985816 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=2.188937
I20260812 06:18:02.998363 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.012s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4189,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:02.998947 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling MajorDeltaCompactionOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=1.000000
I20260812 06:18:03.186730 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: MajorDeltaCompactionOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.188s	user 0.118s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":757,"lbm_read_time_us":12663,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32466,"lbm_writes_lt_1ms":543,"mutex_wait_us":49,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8576,"update_count":2500}
I20260812 06:18:03.187284 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=14.095187
I20260812 06:18:03.253211 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.066s	user 0.028s	sys 0.028s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":27085,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:03.253875 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=2.188937
I20260812 06:18:03.268405 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5861,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:03.268949 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling MajorDeltaCompactionOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=1.000000
I20260812 06:18:03.447405 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: MajorDeltaCompactionOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.178s	user 0.102s	sys 0.076s 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":356,"lbm_read_time_us":12773,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30934,"lbm_writes_lt_1ms":543,"mutex_wait_us":123,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20096,"update_count":2500}
I20260812 06:18:03.448011 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=14.095187
I20260812 06:18:03.510036 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.062s	user 0.037s	sys 0.016s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22471,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:03.510620 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=2.188937
I20260812 06:18:03.522225 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4313,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:03.522680 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushMRSOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=1.000000
I20260812 06:18:03.555608 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushMRSOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.033s	user 0.028s	sys 0.003s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":216,"dirs.run_wall_time_us":1458,"drs_written":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2315,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:03.556370 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling LogGCOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): free 112692317 bytes of WAL
I20260812 06:18:03.556627 25396 log_reader.cc:385] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1: removed 11 log segments from log reader
I20260812 06:18:03.556696 25396 log.cc:1079] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/8e1f2e7a4a6248d2a4ecaad6b1d5bda1/wal-000000015 (ops 69-73)
I20260812 06:18:03.556756 25396 log.cc:1079] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/8e1f2e7a4a6248d2a4ecaad6b1d5bda1/wal-000000016 (ops 74-78)
I20260812 06:18:03.556815 25396 log.cc:1079] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/8e1f2e7a4a6248d2a4ecaad6b1d5bda1/wal-000000017 (ops 79-83)
I20260812 06:18:03.556859 25396 log.cc:1079] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/8e1f2e7a4a6248d2a4ecaad6b1d5bda1/wal-000000018 (ops 84-88)
I20260812 06:18:03.556896 25396 log.cc:1079] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/8e1f2e7a4a6248d2a4ecaad6b1d5bda1/wal-000000019 (ops 89-93)
I20260812 06:18:03.556936 25396 log.cc:1079] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/8e1f2e7a4a6248d2a4ecaad6b1d5bda1/wal-000000020 (ops 94-98)
I20260812 06:18:03.556972 25396 log.cc:1079] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/8e1f2e7a4a6248d2a4ecaad6b1d5bda1/wal-000000021 (ops 99-103)
I20260812 06:18:03.557010 25396 log.cc:1079] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/8e1f2e7a4a6248d2a4ecaad6b1d5bda1/wal-000000022 (ops 104-108)
I20260812 06:18:03.557049 25396 log.cc:1079] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/8e1f2e7a4a6248d2a4ecaad6b1d5bda1/wal-000000023 (ops 109-113)
I20260812 06:18:03.557088 25396 log.cc:1079] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/8e1f2e7a4a6248d2a4ecaad6b1d5bda1/wal-000000024 (ops 114-118)
I20260812 06:18:03.557126 25396 log.cc:1079] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/8e1f2e7a4a6248d2a4ecaad6b1d5bda1/wal-000000025 (ops 119-123)
I20260812 06:18:03.581931 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: LogGCOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.025s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:18:03.582404 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling UndoDeltaBlockGCOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): 462 bytes on disk
I20260812 06:18:03.582892 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: UndoDeltaBlockGCOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4,"spinlock_wait_cycles":896}
I20260812 06:18:03.583767 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=2.188937
I20260812 06:18:03.599640 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.016s	user 0.004s	sys 0.006s Metrics: {"bytes_written":4307782,"delete_count":0,"lbm_write_time_us":4194,"lbm_writes_lt_1ms":108,"reinsert_count":0,"update_count":525}
I20260812 06:18:03.600179 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling LogGCOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): free 12017983 bytes of WAL
I20260812 06:18:03.600468 25396 log_reader.cc:385] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1: removed 1 log segments from log reader
I20260812 06:18:03.600533 25396 log.cc:1079] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/8e1f2e7a4a6248d2a4ecaad6b1d5bda1/wal-000000026 (ops 124-128)
I20260812 06:18:03.603520 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: LogGCOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:18:03.603955 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=2.188937
I20260812 06:18:03.619441 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3897533,"delete_count":0,"lbm_write_time_us":5468,"lbm_writes_lt_1ms":98,"reinsert_count":0,"update_count":475}
I20260812 06:18:03.620494 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling MajorDeltaCompactionOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=1.000000
I20260812 06:18:03.853861 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: MajorDeltaCompactionOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.233s	user 0.164s	sys 0.064s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979746,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":202,"lbm_read_time_us":15370,"lbm_reads_lt_1ms":774,"lbm_write_time_us":40581,"lbm_writes_lt_1ms":743,"mutex_wait_us":24,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":71552,"thread_start_us":88,"threads_started":1,"update_count":3500}
I20260812 06:18:03.854629 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=18.063937
I20260812 06:18:03.914477 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.059s	user 0.046s	sys 0.012s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":25498,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:03.915369 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=2.188937
I20260812 06:18:03.931165 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5889,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:03.931725 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling MajorDeltaCompactionOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=1.000000
I20260812 06:18:04.101423 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: MajorDeltaCompactionOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.169s	user 0.149s	sys 0.020s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877101,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":590,"lbm_read_time_us":11174,"lbm_reads_lt_1ms":664,"lbm_write_time_us":34003,"lbm_writes_lt_1ms":643,"mutex_wait_us":324,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:18:04.102190 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=14.095187
I20260812 06:18:04.149996 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.047s	user 0.036s	sys 0.011s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":21309,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:04.150642 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=2.188937
I20260812 06:18:04.167026 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.016s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6412,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:04.167513 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling MajorDeltaCompactionOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=1.000000
I20260812 06:18:04.328639 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: MajorDeltaCompactionOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.161s	user 0.105s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":234,"lbm_read_time_us":9832,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32634,"lbm_writes_lt_1ms":543,"mutex_wait_us":61,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17024,"update_count":2500}
I20260812 06:18:04.329380 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=12.110812
I20260812 06:18:04.372634 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.043s	user 0.012s	sys 0.027s Metrics: {"bytes_written":13702313,"delete_count":0,"lbm_write_time_us":18734,"lbm_writes_lt_1ms":337,"reinsert_count":0,"update_count":1670}
I20260812 06:18:04.373484 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=1.196750
I20260812 06:18:04.386091 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.012s	user 0.011s	sys 0.001s Metrics: {"bytes_written":2707805,"delete_count":0,"lbm_write_time_us":4217,"lbm_writes_lt_1ms":69,"reinsert_count":0,"update_count":330}
I20260812 06:18:04.386569 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling MajorDeltaCompactionOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=1.000000
I20260812 06:18:04.535254 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: MajorDeltaCompactionOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.149s	user 0.112s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672246,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":591,"lbm_read_time_us":9647,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25654,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:04.537808 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=10.126437
I20260812 06:18:04.571678 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.033s	user 0.022s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14476,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:04.572170 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=2.188937
I20260812 06:18:04.592623 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.020s	user 0.005s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5699,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:04.593513 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling MajorDeltaCompactionOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=1.000000
I20260812 06:18:04.746390 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: MajorDeltaCompactionOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.153s	user 0.103s	sys 0.048s 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":258,"lbm_read_time_us":10735,"lbm_reads_lt_1ms":464,"lbm_write_time_us":30177,"lbm_writes_lt_1ms":443,"mutex_wait_us":31,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:04.747126 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=11.118625
I20260812 06:18:04.783943 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.036s	user 0.014s	sys 0.020s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16105,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:04.784493 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=2.188937
I20260812 06:18:04.798666 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.014s	user 0.003s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5101,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:04.799327 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling MajorDeltaCompactionOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=1.000000
I20260812 06:18:04.928812 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: MajorDeltaCompactionOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.129s	user 0.115s	sys 0.013s 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":910,"lbm_read_time_us":10576,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23399,"lbm_writes_lt_1ms":443,"mutex_wait_us":586,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":24832,"update_count":2000}
I20260812 06:18:04.929721 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=10.126437
I20260812 06:18:04.963526 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.034s	user 0.019s	sys 0.013s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14635,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:04.964150 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=2.188937
I20260812 06:18:04.978310 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.014s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5520,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:04.978873 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushMRSOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=1.000000
I20260812 06:18:05.010710 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushMRSOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.032s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1193505,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":276,"dirs.run_wall_time_us":1360,"drs_written":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2276,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:05.011399 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling LogGCOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): free 112239567 bytes of WAL
I20260812 06:18:05.011638 25396 log_reader.cc:385] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1: removed 11 log segments from log reader
I20260812 06:18:05.011701 25396 log.cc:1079] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/8e1f2e7a4a6248d2a4ecaad6b1d5bda1/wal-000000027 (ops 129-133)
I20260812 06:18:05.011750 25396 log.cc:1079] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/8e1f2e7a4a6248d2a4ecaad6b1d5bda1/wal-000000028 (ops 134-138)
I20260812 06:18:05.011811 25396 log.cc:1079] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/8e1f2e7a4a6248d2a4ecaad6b1d5bda1/wal-000000029 (ops 139-142)
I20260812 06:18:05.011855 25396 log.cc:1079] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/8e1f2e7a4a6248d2a4ecaad6b1d5bda1/wal-000000030 (ops 143-147)
I20260812 06:18:05.011893 25396 log.cc:1079] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/8e1f2e7a4a6248d2a4ecaad6b1d5bda1/wal-000000031 (ops 148-152)
I20260812 06:18:05.011932 25396 log.cc:1079] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/8e1f2e7a4a6248d2a4ecaad6b1d5bda1/wal-000000032 (ops 153-157)
I20260812 06:18:05.011970 25396 log.cc:1079] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/8e1f2e7a4a6248d2a4ecaad6b1d5bda1/wal-000000033 (ops 158-162)
I20260812 06:18:05.012012 25396 log.cc:1079] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/8e1f2e7a4a6248d2a4ecaad6b1d5bda1/wal-000000034 (ops 163-167)
I20260812 06:18:05.012050 25396 log.cc:1079] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/8e1f2e7a4a6248d2a4ecaad6b1d5bda1/wal-000000035 (ops 168-172)
I20260812 06:18:05.012089 25396 log.cc:1079] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/8e1f2e7a4a6248d2a4ecaad6b1d5bda1/wal-000000036 (ops 173-177)
I20260812 06:18:05.012128 25396 log.cc:1079] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: Deleting log segment in path: /tmp/dist-test-task0MeKYf/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515474545641-25072-0/minicluster-data/ts-0-root/wals/8e1f2e7a4a6248d2a4ecaad6b1d5bda1/wal-000000037 (ops 178-182)
I20260812 06:18:05.036464 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: LogGCOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.025s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:18:05.036911 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling UndoDeltaBlockGCOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): 461 bytes on disk
I20260812 06:18:05.037387 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: UndoDeltaBlockGCOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4}
I20260812 06:18:05.038223 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=2.188937
I20260812 06:18:05.052047 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.014s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4266759,"delete_count":0,"lbm_write_time_us":4557,"lbm_writes_lt_1ms":107,"reinsert_count":0,"update_count":520}
I20260812 06:18:05.052552 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=2.188937
I20260812 06:18:05.063081 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3938558,"delete_count":0,"lbm_write_time_us":3807,"lbm_writes_lt_1ms":99,"reinsert_count":0,"update_count":480}
I20260812 06:18:05.063596 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling MajorDeltaCompactionOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=1.000000
I20260812 06:18:05.249365 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: MajorDeltaCompactionOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.186s	user 0.125s	sys 0.060s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877337,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":532,"lbm_read_time_us":12781,"lbm_reads_lt_1ms":674,"lbm_write_time_us":39069,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5632,"thread_start_us":77,"threads_started":1,"update_count":3000}
I20260812 06:18:05.250005 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=14.095187
I20260812 06:18:05.305192 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.055s	user 0.037s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23834,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:05.305896 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=2.188937
I20260812 06:18:05.317884 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4126,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:05.318655 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling MajorDeltaCompactionOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=1.000000
I20260812 06:18:05.395417 25072 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.903s	user 1.896s	sys 0.126s
I20260812 06:18:05.469591 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: MajorDeltaCompactionOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.151s	user 0.118s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":382,"lbm_read_time_us":10003,"lbm_reads_lt_1ms":568,"lbm_write_time_us":31226,"lbm_writes_lt_1ms":543,"mutex_wait_us":83,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":21504,"update_count":2500}
I20260812 06:18:05.470494 25464 maintenance_manager.cc:419] P e521c9c8251543b6853ad08cfca6f5d8: Scheduling FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1): perf score=6.157687
I20260812 06:18:05.471902 25072 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.076s	user 0.005s	sys 0.000s
I20260812 06:18:05.472527 25072 tablet_server.cc:179] TabletServer@127.24.124.1:0 shutting down...
I20260812 06:18:05.493556 25396 maintenance_manager.cc:643] P e521c9c8251543b6853ad08cfca6f5d8: FlushDeltaMemStoresOp(8e1f2e7a4a6248d2a4ecaad6b1d5bda1) complete. Timing: real 0.023s	user 0.013s	sys 0.007s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10026,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:05.494249 25072 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:05.494468 25072 tablet_replica.cc:333] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8: stopping tablet replica
I20260812 06:18:05.494665 25072 raft_consensus.cc:2243] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:05.494899 25072 raft_consensus.cc:2272] T 8e1f2e7a4a6248d2a4ecaad6b1d5bda1 P e521c9c8251543b6853ad08cfca6f5d8 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:05.498611 25072 tablet_server.cc:196] TabletServer@127.24.124.1:0 shutdown complete.
I20260812 06:18:05.515818 25072 master.cc:562] Master@127.24.124.62:39491 shutting down...
I20260812 06:18:05.519265 25072 raft_consensus.cc:2243] T 00000000000000000000000000000000 P fe9bef8370314a9eafd77882896ee41a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:05.519476 25072 raft_consensus.cc:2272] T 00000000000000000000000000000000 P fe9bef8370314a9eafd77882896ee41a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:05.519572 25072 tablet_replica.cc:333] T 00000000000000000000000000000000 P fe9bef8370314a9eafd77882896ee41a: stopping tablet replica
I20260812 06:18:05.532255 25072 master.cc:584] Master@127.24.124.62:39491 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5383 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11064 ms total)

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