[==========] 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:33.955901 13246 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.12.239.190:32975
I20260812 06:17:33.956768 13246 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:33.957273 13246 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:33.963014 13262 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:33.963020 13257 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:33.963187 13246 server_base.cc:1061] running on GCE node
W20260812 06:17:33.963234 13255 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:33.963655 13246 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:33.963742 13246 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:33.963768 13246 hybrid_clock.cc:648] HybridClock initialized: now 1786515453963766 us; error 0 us; skew 500 ppm
I20260812 06:17:33.965250 13246 webserver.cc:533] Webserver started at http://127.12.239.190:44409/ using document root <none> and password file <none>
I20260812 06:17:33.965723 13246 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:33.965781 13246 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:33.965953 13246 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:33.967424 13246 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/master-0-root/instance:
uuid: "07a0059124a641f8a03ecbffba17f812"
format_stamp: "Formatted at 2026-08-12 06:17:33 on dist-test-slave-42z9"
I20260812 06:17:33.970587 13246 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:17:33.972406 13271 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:33.973304 13246 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:33.973405 13246 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/master-0-root
uuid: "07a0059124a641f8a03ecbffba17f812"
format_stamp: "Formatted at 2026-08-12 06:17:33 on dist-test-slave-42z9"
I20260812 06:17:33.973517 13246 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-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:33.994616 13246 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:33.995157 13246 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:33.995298 13246 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:34.002015 13246 rpc_server.cc:307] RPC server started. Bound to: 127.12.239.190:32975
I20260812 06:17:34.002022 13367 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.239.190:32975 every 8 connection(s)
I20260812 06:17:34.004091 13368 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:34.009032 13368 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 07a0059124a641f8a03ecbffba17f812: Bootstrap starting.
I20260812 06:17:34.011163 13368 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 07a0059124a641f8a03ecbffba17f812: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:34.011962 13368 log.cc:826] T 00000000000000000000000000000000 P 07a0059124a641f8a03ecbffba17f812: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:34.013433 13368 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 07a0059124a641f8a03ecbffba17f812: No bootstrap required, opened a new log
I20260812 06:17:34.015962 13368 raft_consensus.cc:359] T 00000000000000000000000000000000 P 07a0059124a641f8a03ecbffba17f812 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "07a0059124a641f8a03ecbffba17f812" member_type: VOTER }
I20260812 06:17:34.016120 13368 raft_consensus.cc:385] T 00000000000000000000000000000000 P 07a0059124a641f8a03ecbffba17f812 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:34.016196 13368 raft_consensus.cc:740] T 00000000000000000000000000000000 P 07a0059124a641f8a03ecbffba17f812 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 07a0059124a641f8a03ecbffba17f812, State: Initialized, Role: FOLLOWER
I20260812 06:17:34.016709 13368 consensus_queue.cc:260] T 00000000000000000000000000000000 P 07a0059124a641f8a03ecbffba17f812 [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: "07a0059124a641f8a03ecbffba17f812" member_type: VOTER }
I20260812 06:17:34.016846 13368 raft_consensus.cc:399] T 00000000000000000000000000000000 P 07a0059124a641f8a03ecbffba17f812 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:34.016909 13368 raft_consensus.cc:493] T 00000000000000000000000000000000 P 07a0059124a641f8a03ecbffba17f812 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:34.017031 13368 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 07a0059124a641f8a03ecbffba17f812 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:34.017747 13368 raft_consensus.cc:515] T 00000000000000000000000000000000 P 07a0059124a641f8a03ecbffba17f812 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "07a0059124a641f8a03ecbffba17f812" member_type: VOTER }
I20260812 06:17:34.018137 13368 leader_election.cc:304] T 00000000000000000000000000000000 P 07a0059124a641f8a03ecbffba17f812 [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: 07a0059124a641f8a03ecbffba17f812; no voters: 
I20260812 06:17:34.018473 13368 leader_election.cc:290] T 00000000000000000000000000000000 P 07a0059124a641f8a03ecbffba17f812 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:34.018584 13371 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 07a0059124a641f8a03ecbffba17f812 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:34.018790 13371 raft_consensus.cc:697] T 00000000000000000000000000000000 P 07a0059124a641f8a03ecbffba17f812 [term 1 LEADER]: Becoming Leader. State: Replica: 07a0059124a641f8a03ecbffba17f812, State: Running, Role: LEADER
I20260812 06:17:34.019167 13371 consensus_queue.cc:237] T 00000000000000000000000000000000 P 07a0059124a641f8a03ecbffba17f812 [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: "07a0059124a641f8a03ecbffba17f812" member_type: VOTER }
I20260812 06:17:34.019312 13368 sys_catalog.cc:565] T 00000000000000000000000000000000 P 07a0059124a641f8a03ecbffba17f812 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:34.020859 13375 sys_catalog.cc:455] T 00000000000000000000000000000000 P 07a0059124a641f8a03ecbffba17f812 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 07a0059124a641f8a03ecbffba17f812. Latest consensus state: current_term: 1 leader_uuid: "07a0059124a641f8a03ecbffba17f812" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "07a0059124a641f8a03ecbffba17f812" member_type: VOTER } }
I20260812 06:17:34.020928 13372 sys_catalog.cc:455] T 00000000000000000000000000000000 P 07a0059124a641f8a03ecbffba17f812 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "07a0059124a641f8a03ecbffba17f812" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "07a0059124a641f8a03ecbffba17f812" member_type: VOTER } }
I20260812 06:17:34.020977 13375 sys_catalog.cc:458] T 00000000000000000000000000000000 P 07a0059124a641f8a03ecbffba17f812 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:34.020983 13372 sys_catalog.cc:458] T 00000000000000000000000000000000 P 07a0059124a641f8a03ecbffba17f812 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:34.021363 13390 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:34.023649 13390 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:34.023893 13246 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:34.027981 13390 catalog_manager.cc:1383] Generated new cluster ID: ce91ff6c6b584d01adfa9f680b37887f
I20260812 06:17:34.028043 13390 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:34.045348 13390 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:34.046113 13390 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:34.065027 13390 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 07a0059124a641f8a03ecbffba17f812: Generated new TSK 0
I20260812 06:17:34.065675 13390 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:34.088564 13246 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:34.091295 13407 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:34.091451 13246 server_base.cc:1061] running on GCE node
W20260812 06:17:34.091569 13410 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:34.091674 13408 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:34.091851 13246 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:34.091892 13246 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:34.091907 13246 hybrid_clock.cc:648] HybridClock initialized: now 1786515454091906 us; error 0 us; skew 500 ppm
I20260812 06:17:34.092756 13246 webserver.cc:533] Webserver started at http://127.12.239.129:41733/ using document root <none> and password file <none>
I20260812 06:17:34.092912 13246 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:34.093025 13246 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:34.093111 13246 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:34.093544 13246 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root/instance:
uuid: "a4f864fa18374446b01b75e043ac8fc6"
format_stamp: "Formatted at 2026-08-12 06:17:34 on dist-test-slave-42z9"
I20260812 06:17:34.094920 13246 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:34.095808 13417 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:34.096045 13246 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:34.096112 13246 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root
uuid: "a4f864fa18374446b01b75e043ac8fc6"
format_stamp: "Formatted at 2026-08-12 06:17:34 on dist-test-slave-42z9"
I20260812 06:17:34.096177 13246 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:34.103554 13246 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:34.103901 13246 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:34.104313 13246 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:34.105088 13246 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:34.105136 13246 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:34.105178 13246 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:34.105207 13246 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:34.111411 13246 rpc_server.cc:307] RPC server started. Bound to: 127.12.239.129:35905
I20260812 06:17:34.111482 13518 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.239.129:35905 every 8 connection(s)
I20260812 06:17:34.120613 13521 heartbeater.cc:344] Connected to a master server at 127.12.239.190:32975
I20260812 06:17:34.120824 13521 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:34.121253 13521 heartbeater.cc:507] Master 127.12.239.190:32975 requested a full tablet report, sending...
I20260812 06:17:34.122620 13298 ts_manager.cc:194] Registered new tserver with Master: a4f864fa18374446b01b75e043ac8fc6 (127.12.239.129:35905)
I20260812 06:17:34.123100 13246 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011101033s
I20260812 06:17:34.123744 13298 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:57062
I20260812 06:17:34.131899 13298 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:57074:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:34.145794 13459 tablet_service.cc:1511] Processing CreateTablet for tablet b643e593fdfc4e6480469b952586dfc4 (DEFAULT_TABLE table=heavy-update-compaction-test [id=ddafbbdefac34a1b8713ec68039da597]), partition=
I20260812 06:17:34.146186 13459 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet b643e593fdfc4e6480469b952586dfc4. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:34.148401 13543 tablet_bootstrap.cc:492] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Bootstrap starting.
I20260812 06:17:34.149276 13543 tablet_bootstrap.cc:654] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:34.150455 13543 tablet_bootstrap.cc:492] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: No bootstrap required, opened a new log
I20260812 06:17:34.150549 13543 ts_tablet_manager.cc:1403] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.001s
I20260812 06:17:34.151151 13543 raft_consensus.cc:359] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a4f864fa18374446b01b75e043ac8fc6" member_type: VOTER last_known_addr { host: "127.12.239.129" port: 35905 } }
I20260812 06:17:34.151247 13543 raft_consensus.cc:385] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:34.151278 13543 raft_consensus.cc:740] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a4f864fa18374446b01b75e043ac8fc6, State: Initialized, Role: FOLLOWER
I20260812 06:17:34.151402 13543 consensus_queue.cc:260] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6 [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: "a4f864fa18374446b01b75e043ac8fc6" member_type: VOTER last_known_addr { host: "127.12.239.129" port: 35905 } }
I20260812 06:17:34.151495 13543 raft_consensus.cc:399] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:34.151539 13543 raft_consensus.cc:493] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:34.151588 13543 raft_consensus.cc:3060] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:34.152279 13543 raft_consensus.cc:515] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a4f864fa18374446b01b75e043ac8fc6" member_type: VOTER last_known_addr { host: "127.12.239.129" port: 35905 } }
I20260812 06:17:34.152410 13543 leader_election.cc:304] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6 [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: a4f864fa18374446b01b75e043ac8fc6; no voters: 
I20260812 06:17:34.152585 13543 leader_election.cc:290] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:34.152690 13547 raft_consensus.cc:2804] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:34.152920 13543 ts_tablet_manager.cc:1434] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:17:34.152917 13547 raft_consensus.cc:697] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6 [term 1 LEADER]: Becoming Leader. State: Replica: a4f864fa18374446b01b75e043ac8fc6, State: Running, Role: LEADER
I20260812 06:17:34.153090 13547 consensus_queue.cc:237] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6 [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: "a4f864fa18374446b01b75e043ac8fc6" member_type: VOTER last_known_addr { host: "127.12.239.129" port: 35905 } }
I20260812 06:17:34.153218 13521 heartbeater.cc:499] Master 127.12.239.190:32975 was elected leader, sending a full tablet report...
I20260812 06:17:34.155750 13298 catalog_manager.cc:5719] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6 reported cstate change: term changed from 0 to 1, leader changed from <none> to a4f864fa18374446b01b75e043ac8fc6 (127.12.239.129). New cstate: current_term: 1 leader_uuid: "a4f864fa18374446b01b75e043ac8fc6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a4f864fa18374446b01b75e043ac8fc6" member_type: VOTER last_known_addr { host: "127.12.239.129" port: 35905 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:34.211069 13246 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.050s	user 0.018s	sys 0.007s
I20260812 06:17:34.362361 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushMRSOp(b643e593fdfc4e6480469b952586dfc4): perf score=23.023690
I20260812 06:17:34.563484 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushMRSOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.201s	user 0.137s	sys 0.061s Metrics: {"bytes_written":16409902,"cfile_init":1,"compiler_manager_pool.queue_time_us":198,"delete_count":0,"dirs.queue_time_us":48,"dirs.run_cpu_time_us":191,"dirs.run_wall_time_us":845,"drs_written":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4,"lbm_write_time_us":51151,"lbm_writes_lt_1ms":957,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"thread_start_us":107,"threads_started":1,"update_count":2000}
I20260812 06:17:34.564775 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling LogGCOp(b643e593fdfc4e6480469b952586dfc4): free 20743880 bytes of WAL
I20260812 06:17:34.565117 13425 log_reader.cc:385] T b643e593fdfc4e6480469b952586dfc4: removed 2 log segments from log reader
I20260812 06:17:34.565197 13425 log.cc:1079] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/b643e593fdfc4e6480469b952586dfc4/wal-000000001 (ops 1-6)
I20260812 06:17:34.565261 13425 log.cc:1079] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/b643e593fdfc4e6480469b952586dfc4/wal-000000002 (ops 7-11)
I20260812 06:17:34.570434 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: LogGCOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.005s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:17:34.570825 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling UndoDeltaBlockGCOp(b643e593fdfc4e6480469b952586dfc4): 20513809 bytes on disk
I20260812 06:17:34.571336 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: UndoDeltaBlockGCOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4}
I20260812 06:17:34.571789 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=6.157687
I20260812 06:17:34.596303 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.024s	user 0.012s	sys 0.009s Metrics: {"bytes_written":8164054,"delete_count":0,"lbm_write_time_us":9844,"lbm_writes_lt_1ms":202,"reinsert_count":0,"update_count":995}
I20260812 06:17:34.596788 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4): perf score=1.000000
I20260812 06:17:34.777935 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.181s	user 0.133s	sys 0.046s Metrics: {"cfile_cache_miss":631,"cfile_cache_miss_bytes":28877073,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":452,"lbm_read_time_us":9394,"lbm_reads_lt_1ms":659,"lbm_write_time_us":30888,"lbm_writes_lt_1ms":642,"peak_mem_usage":75501437,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":277,"threads_started":5,"update_count":2995}
I20260812 06:17:34.778452 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=14.095187
I20260812 06:17:34.818635 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.040s	user 0.027s	sys 0.012s Metrics: {"bytes_written":16450932,"delete_count":0,"lbm_write_time_us":17578,"lbm_writes_lt_1ms":404,"reinsert_count":0,"update_count":2005}
I20260812 06:17:34.819188 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4): perf score=1.000000
I20260812 06:17:34.944344 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.125s	user 0.093s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20754183,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":194,"lbm_read_time_us":9260,"lbm_reads_lt_1ms":468,"lbm_write_time_us":18573,"lbm_writes_lt_1ms":444,"mutex_wait_us":34,"peak_mem_usage":50730363,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2005}
I20260812 06:17:34.944885 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=10.126437
I20260812 06:17:34.974180 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.029s	user 0.021s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12180,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:34.974735 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=2.188937
I20260812 06:17:34.985281 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3748,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.985885 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4): perf score=1.000000
I20260812 06:17:35.107285 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.121s	user 0.094s	sys 0.026s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":113,"lbm_read_time_us":9220,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22232,"lbm_writes_lt_1ms":443,"mutex_wait_us":34,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:17:35.107793 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=10.126437
I20260812 06:17:35.148442 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.040s	user 0.007s	sys 0.021s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13501,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:35.148967 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=2.188937
I20260812 06:17:35.163055 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5138,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.163555 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4): perf score=1.000000
I20260812 06:17:35.281946 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.118s	user 0.098s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":679,"lbm_read_time_us":9443,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22402,"lbm_writes_lt_1ms":443,"mutex_wait_us":308,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18176,"update_count":2000}
I20260812 06:17:35.282450 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=10.126437
I20260812 06:17:35.326074 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.043s	user 0.016s	sys 0.020s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15857,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:35.326538 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=2.188937
I20260812 06:17:35.336239 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3713,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.336612 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4): perf score=1.000000
I20260812 06:17:35.452921 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.116s	user 0.104s	sys 0.012s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":311,"lbm_read_time_us":7737,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22636,"lbm_writes_lt_1ms":443,"mutex_wait_us":54,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:35.453414 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=10.126437
I20260812 06:17:35.501339 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.048s	user 0.022s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14130,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:35.501839 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=2.188937
I20260812 06:17:35.511513 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3671,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.511968 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4): perf score=1.000000
I20260812 06:17:35.651084 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.139s	user 0.081s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":248,"lbm_read_time_us":9982,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22072,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:35.651638 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=10.126437
I20260812 06:17:35.691915 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.040s	user 0.022s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13525,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:35.692427 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=2.188937
I20260812 06:17:35.701877 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.009s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3543,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.702317 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushMRSOp(b643e593fdfc4e6480469b952586dfc4): perf score=1.000000
I20260812 06:17:35.733191 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushMRSOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.031s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":233,"dirs.run_wall_time_us":1245,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1727,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:35.734053 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling LogGCOp(b643e593fdfc4e6480469b952586dfc4): free 124257238 bytes of WAL
I20260812 06:17:35.734282 13425 log_reader.cc:385] T b643e593fdfc4e6480469b952586dfc4: removed 12 log segments from log reader
I20260812 06:17:35.734342 13425 log.cc:1079] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/b643e593fdfc4e6480469b952586dfc4/wal-000000003 (ops 12-16)
I20260812 06:17:35.734388 13425 log.cc:1079] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/b643e593fdfc4e6480469b952586dfc4/wal-000000004 (ops 17-21)
I20260812 06:17:35.734418 13425 log.cc:1079] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/b643e593fdfc4e6480469b952586dfc4/wal-000000005 (ops 22-26)
I20260812 06:17:35.734448 13425 log.cc:1079] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/b643e593fdfc4e6480469b952586dfc4/wal-000000006 (ops 27-31)
I20260812 06:17:35.734477 13425 log.cc:1079] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/b643e593fdfc4e6480469b952586dfc4/wal-000000007 (ops 32-36)
I20260812 06:17:35.734509 13425 log.cc:1079] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/b643e593fdfc4e6480469b952586dfc4/wal-000000008 (ops 37-41)
I20260812 06:17:35.734539 13425 log.cc:1079] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/b643e593fdfc4e6480469b952586dfc4/wal-000000009 (ops 42-46)
I20260812 06:17:35.734566 13425 log.cc:1079] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/b643e593fdfc4e6480469b952586dfc4/wal-000000010 (ops 47-51)
I20260812 06:17:35.734594 13425 log.cc:1079] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/b643e593fdfc4e6480469b952586dfc4/wal-000000011 (ops 52-56)
I20260812 06:17:35.734622 13425 log.cc:1079] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/b643e593fdfc4e6480469b952586dfc4/wal-000000012 (ops 57-61)
I20260812 06:17:35.734654 13425 log.cc:1079] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/b643e593fdfc4e6480469b952586dfc4/wal-000000013 (ops 62-66)
I20260812 06:17:35.734684 13425 log.cc:1079] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/b643e593fdfc4e6480469b952586dfc4/wal-000000014 (ops 67-70)
I20260812 06:17:35.757480 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: LogGCOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.023s	user 0.001s	sys 0.019s Metrics: {}
I20260812 06:17:35.757841 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=3.181125
I20260812 06:17:35.777874 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.020s	user 0.012s	sys 0.008s Metrics: {"bytes_written":4512904,"delete_count":0,"lbm_write_time_us":4634,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:35.778268 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=2.188937
I20260812 06:17:35.791230 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4866,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:35.791656 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling UndoDeltaBlockGCOp(b643e593fdfc4e6480469b952586dfc4): 471 bytes on disk
I20260812 06:17:35.792018 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: UndoDeltaBlockGCOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:17:35.792415 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4): perf score=1.000000
I20260812 06:17:35.971861 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.179s	user 0.102s	sys 0.071s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":354,"lbm_read_time_us":12631,"lbm_reads_lt_1ms":674,"lbm_write_time_us":30990,"lbm_writes_lt_1ms":643,"mutex_wait_us":43,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3200,"thread_start_us":69,"threads_started":1,"update_count":3000}
I20260812 06:17:35.972396 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=11.118625
I20260812 06:17:36.005764 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.033s	user 0.030s	sys 0.003s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13666,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:36.006186 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=2.188937
I20260812 06:17:36.025653 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.019s	user 0.009s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4937,"lbm_writes_lt_1ms":93,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":450}
I20260812 06:17:36.026317 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4): perf score=1.000000
I20260812 06:17:36.180058 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.154s	user 0.069s	sys 0.072s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":254,"lbm_read_time_us":10070,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21443,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:36.180675 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=14.095187
I20260812 06:17:36.225806 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.045s	user 0.022s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":16478,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:36.226217 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=2.188937
I20260812 06:17:36.235283 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3366,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.235879 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4): perf score=1.000000
I20260812 06:17:36.371027 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.135s	user 0.109s	sys 0.023s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":991,"lbm_read_time_us":8801,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26003,"lbm_writes_lt_1ms":543,"mutex_wait_us":465,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:17:36.371536 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=11.118625
I20260812 06:17:36.412634 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.041s	user 0.018s	sys 0.020s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":17818,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:17:36.413161 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=2.188937
I20260812 06:17:36.431491 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.018s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5593,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.431878 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=2.188937
I20260812 06:17:36.440330 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.008s	user 0.003s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3120,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:36.440701 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4): perf score=1.000000
I20260812 06:17:36.566403 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.126s	user 0.117s	sys 0.008s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815796,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1294,"lbm_read_time_us":8102,"lbm_reads_lt_1ms":573,"lbm_write_time_us":25824,"lbm_writes_lt_1ms":543,"mutex_wait_us":295,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:36.566910 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=10.126437
I20260812 06:17:36.601716 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.035s	user 0.015s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13047,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:36.602197 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=2.188937
I20260812 06:17:36.613386 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4131,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.614041 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4): perf score=1.000000
I20260812 06:17:36.728531 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.114s	user 0.082s	sys 0.026s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1327,"lbm_read_time_us":7817,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24579,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":324,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9600,"update_count":2000}
I20260812 06:17:36.730113 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=10.126437
I20260812 06:17:36.774371 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.044s	user 0.027s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17089,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:17:36.774859 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=2.188937
I20260812 06:17:36.785130 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3692,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.785655 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4): perf score=1.000000
I20260812 06:17:36.920900 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.135s	user 0.078s	sys 0.057s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":77,"lbm_read_time_us":9482,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21709,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":50944,"update_count":2000}
I20260812 06:17:36.921624 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=10.126437
I20260812 06:17:36.963990 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.042s	user 0.018s	sys 0.021s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18530,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:36.964540 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=2.188937
I20260812 06:17:36.974558 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3598,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.975219 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushMRSOp(b643e593fdfc4e6480469b952586dfc4): perf score=1.000000
I20260812 06:17:37.000882 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushMRSOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.025s	user 0.023s	sys 0.000s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":216,"dirs.run_wall_time_us":1243,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1209,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:37.001616 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling LogGCOp(b643e593fdfc4e6480469b952586dfc4): free 121006384 bytes of WAL
I20260812 06:17:37.001822 13425 log_reader.cc:385] T b643e593fdfc4e6480469b952586dfc4: removed 12 log segments from log reader
I20260812 06:17:37.001868 13425 log.cc:1079] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/b643e593fdfc4e6480469b952586dfc4/wal-000000015 (ops 71-75)
I20260812 06:17:37.001904 13425 log.cc:1079] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/b643e593fdfc4e6480469b952586dfc4/wal-000000016 (ops 76-80)
I20260812 06:17:37.001973 13425 log.cc:1079] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/b643e593fdfc4e6480469b952586dfc4/wal-000000017 (ops 81-85)
I20260812 06:17:37.002014 13425 log.cc:1079] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/b643e593fdfc4e6480469b952586dfc4/wal-000000018 (ops 86-90)
I20260812 06:17:37.002040 13425 log.cc:1079] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/b643e593fdfc4e6480469b952586dfc4/wal-000000019 (ops 91-94)
I20260812 06:17:37.002080 13425 log.cc:1079] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/b643e593fdfc4e6480469b952586dfc4/wal-000000020 (ops 95-99)
I20260812 06:17:37.002097 13425 log.cc:1079] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/b643e593fdfc4e6480469b952586dfc4/wal-000000021 (ops 100-104)
I20260812 06:17:37.002127 13425 log.cc:1079] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/b643e593fdfc4e6480469b952586dfc4/wal-000000022 (ops 105-109)
I20260812 06:17:37.002157 13425 log.cc:1079] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/b643e593fdfc4e6480469b952586dfc4/wal-000000023 (ops 110-114)
I20260812 06:17:37.002188 13425 log.cc:1079] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/b643e593fdfc4e6480469b952586dfc4/wal-000000024 (ops 115-119)
I20260812 06:17:37.002220 13425 log.cc:1079] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/b643e593fdfc4e6480469b952586dfc4/wal-000000025 (ops 120-124)
I20260812 06:17:37.002254 13425 log.cc:1079] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/b643e593fdfc4e6480469b952586dfc4/wal-000000026 (ops 125-129)
I20260812 06:17:37.023047 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: LogGCOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.021s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:17:37.023490 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling UndoDeltaBlockGCOp(b643e593fdfc4e6480469b952586dfc4): 448 bytes on disk
I20260812 06:17:37.024010 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: UndoDeltaBlockGCOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:17:37.024524 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=3.181125
I20260812 06:17:37.050194 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.026s	user 0.009s	sys 0.014s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7085,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:37.050633 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=2.188937
I20260812 06:17:37.059615 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.009s	user 0.003s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3315,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:37.060010 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4): perf score=1.000000
I20260812 06:17:37.254923 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.195s	user 0.121s	sys 0.067s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918320,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":447,"lbm_read_time_us":12556,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33858,"lbm_writes_lt_1ms":643,"mutex_wait_us":48,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4736,"thread_start_us":67,"threads_started":1,"update_count":3000}
I20260812 06:17:37.255537 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=14.095187
I20260812 06:17:37.315001 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.059s	user 0.036s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18984,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:37.315538 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=2.188937
I20260812 06:17:37.329675 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.014s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5487,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.330127 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4): perf score=1.000000
I20260812 06:17:37.493970 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.164s	user 0.088s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":582,"lbm_read_time_us":11453,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25908,"lbm_writes_lt_1ms":543,"mutex_wait_us":37,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:17:37.494499 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=14.095187
I20260812 06:17:37.538846 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.044s	user 0.024s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":15944,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:37.539322 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=2.188937
I20260812 06:17:37.561077 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.022s	user 0.003s	sys 0.015s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5750,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.561621 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4): perf score=1.000000
I20260812 06:17:37.723629 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.162s	user 0.123s	sys 0.029s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":133,"lbm_read_time_us":10834,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25475,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:37.724154 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=14.095187
I20260812 06:17:37.775233 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.051s	user 0.034s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25162,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:37.775652 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=2.188937
I20260812 06:17:37.786804 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4139,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.787209 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4): perf score=1.000000
I20260812 06:17:37.948521 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.161s	user 0.108s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":157,"lbm_read_time_us":7863,"lbm_reads_lt_1ms":564,"lbm_write_time_us":25989,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4608,"update_count":2500}
I20260812 06:17:37.949044 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=14.095187
I20260812 06:17:38.002619 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.053s	user 0.044s	sys 0.000s Metrics: {"bytes_written":16409895,"delete_count":0,"lbm_write_time_us":19581,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2000}
I20260812 06:17:38.003147 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=2.188937
I20260812 06:17:38.013538 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3733,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:38.013968 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4): perf score=1.000000
I20260812 06:17:38.154795 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.141s	user 0.103s	sys 0.027s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815677,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":121,"lbm_read_time_us":8774,"lbm_reads_lt_1ms":572,"lbm_write_time_us":24637,"lbm_writes_lt_1ms":543,"mutex_wait_us":33,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:17:38.155388 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=14.095187
I20260812 06:17:38.205574 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.050s	user 0.033s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24245,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:38.206131 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=2.188937
I20260812 06:17:38.223784 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.017s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5886,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:38.224231 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushMRSOp(b643e593fdfc4e6480469b952586dfc4): perf score=1.000000
I20260812 06:17:38.251930 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushMRSOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.028s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":190,"dirs.run_wall_time_us":1177,"drs_written":1,"lbm_read_time_us":35,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1200,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:38.252569 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling LogGCOp(b643e593fdfc4e6480469b952586dfc4): free 112239606 bytes of WAL
I20260812 06:17:38.252789 13425 log_reader.cc:385] T b643e593fdfc4e6480469b952586dfc4: removed 11 log segments from log reader
I20260812 06:17:38.252836 13425 log.cc:1079] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/b643e593fdfc4e6480469b952586dfc4/wal-000000027 (ops 130-134)
I20260812 06:17:38.252863 13425 log.cc:1079] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/b643e593fdfc4e6480469b952586dfc4/wal-000000028 (ops 135-139)
I20260812 06:17:38.252880 13425 log.cc:1079] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/b643e593fdfc4e6480469b952586dfc4/wal-000000029 (ops 140-144)
I20260812 06:17:38.252914 13425 log.cc:1079] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/b643e593fdfc4e6480469b952586dfc4/wal-000000030 (ops 145-149)
I20260812 06:17:38.252948 13425 log.cc:1079] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/b643e593fdfc4e6480469b952586dfc4/wal-000000031 (ops 150-154)
I20260812 06:17:38.252974 13425 log.cc:1079] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/b643e593fdfc4e6480469b952586dfc4/wal-000000032 (ops 155-158)
I20260812 06:17:38.253005 13425 log.cc:1079] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/b643e593fdfc4e6480469b952586dfc4/wal-000000033 (ops 159-163)
I20260812 06:17:38.253029 13425 log.cc:1079] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/b643e593fdfc4e6480469b952586dfc4/wal-000000034 (ops 164-168)
I20260812 06:17:38.253051 13425 log.cc:1079] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/b643e593fdfc4e6480469b952586dfc4/wal-000000035 (ops 169-173)
I20260812 06:17:38.253073 13425 log.cc:1079] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/b643e593fdfc4e6480469b952586dfc4/wal-000000036 (ops 174-178)
I20260812 06:17:38.253094 13425 log.cc:1079] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/b643e593fdfc4e6480469b952586dfc4/wal-000000037 (ops 179-183)
I20260812 06:17:38.272071 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: LogGCOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.019s	user 0.000s	sys 0.017s Metrics: {}
I20260812 06:17:38.272481 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling UndoDeltaBlockGCOp(b643e593fdfc4e6480469b952586dfc4): 446 bytes on disk
I20260812 06:17:38.272971 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: UndoDeltaBlockGCOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4}
I20260812 06:17:38.273638 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=4.173312
I20260812 06:17:38.286271 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.012s	user 0.011s	sys 0.001s Metrics: {"bytes_written":5415441,"delete_count":0,"lbm_write_time_us":5060,"lbm_writes_lt_1ms":135,"reinsert_count":0,"update_count":660}
I20260812 06:17:38.286675 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=1.196750
I20260812 06:17:38.301856 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.015s	user 0.008s	sys 0.007s Metrics: {"bytes_written":2789855,"delete_count":0,"lbm_write_time_us":2419,"lbm_writes_lt_1ms":71,"reinsert_count":0,"update_count":340}
I20260812 06:17:38.302250 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4): perf score=1.000000
I20260812 06:17:38.501019 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.199s	user 0.141s	sys 0.057s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020717,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":834,"lbm_read_time_us":13281,"lbm_reads_lt_1ms":774,"lbm_write_time_us":33315,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"thread_start_us":71,"threads_started":1,"update_count":3500}
I20260812 06:17:38.501624 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=14.095187
I20260812 06:17:38.550809 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.049s	user 0.019s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18091,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:38.551362 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=2.188937
I20260812 06:17:38.561079 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3641,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:38.561556 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4): perf score=1.000000
I20260812 06:17:38.679585 13246 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.468s	user 1.618s	sys 0.142s
I20260812 06:17:38.702906 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.141s	user 0.095s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"lbm_read_time_us":10859,"lbm_reads_lt_1ms":568,"lbm_write_time_us":23498,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:17:38.703467 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4): perf score=10.126437
I20260812 06:17:38.729329 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: FlushDeltaMemStoresOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.026s	user 0.016s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":11010,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:38.729982 13523 maintenance_manager.cc:419] P a4f864fa18374446b01b75e043ac8fc6: Scheduling MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4): perf score=1.000000
I20260812 06:17:38.732964 13246 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.053s	user 0.001s	sys 0.000s
I20260812 06:17:38.733557 13246 tablet_server.cc:179] TabletServer@127.12.239.129:0 shutting down...
I20260812 06:17:38.820881 13425 maintenance_manager.cc:643] P a4f864fa18374446b01b75e043ac8fc6: MajorDeltaCompactionOp(b643e593fdfc4e6480469b952586dfc4) complete. Timing: real 0.091s	user 0.070s	sys 0.020s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16610741,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":406,"lbm_read_time_us":5889,"lbm_reads_lt_1ms":367,"lbm_write_time_us":17966,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":342,"mutex_wait_us":122,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":1500}
I20260812 06:17:38.821563 13246 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:38.822024 13246 tablet_replica.cc:333] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6: stopping tablet replica
I20260812 06:17:38.822245 13246 raft_consensus.cc:2243] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:38.822464 13246 raft_consensus.cc:2272] T b643e593fdfc4e6480469b952586dfc4 P a4f864fa18374446b01b75e043ac8fc6 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:38.837656 13246 tablet_server.cc:196] TabletServer@127.12.239.129:0 shutdown complete.
I20260812 06:17:38.851981 13246 master.cc:562] Master@127.12.239.190:32975 shutting down...
I20260812 06:17:38.855006 13246 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 07a0059124a641f8a03ecbffba17f812 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:38.855175 13246 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 07a0059124a641f8a03ecbffba17f812 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:38.855247 13246 tablet_replica.cc:333] T 00000000000000000000000000000000 P 07a0059124a641f8a03ecbffba17f812: stopping tablet replica
I20260812 06:17:38.867290 13246 master.cc:584] Master@127.12.239.190:32975 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (4982 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:38.938575 13246 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.12.239.190:45539
I20260812 06:17:38.938936 13246 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:38.940716 13577 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:38.940804 13575 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:38.940867 13246 server_base.cc:1061] running on GCE node
W20260812 06:17:38.940928 13579 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:38.941103 13246 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:38.941147 13246 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:38.941167 13246 hybrid_clock.cc:648] HybridClock initialized: now 1786515458941167 us; error 0 us; skew 500 ppm
I20260812 06:17:38.942010 13246 webserver.cc:533] Webserver started at http://127.12.239.190:34101/ using document root <none> and password file <none>
I20260812 06:17:38.942157 13246 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:38.942201 13246 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:38.942271 13246 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:38.942626 13246 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/master-0-root/instance:
uuid: "6dff78a4b1754d509e7cf7f834b7b1ed"
format_stamp: "Formatted at 2026-08-12 06:17:38 on dist-test-slave-42z9"
I20260812 06:17:38.943984 13246 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:38.944794 13591 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:38.944988 13246 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:38.945057 13246 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/master-0-root
uuid: "6dff78a4b1754d509e7cf7f834b7b1ed"
format_stamp: "Formatted at 2026-08-12 06:17:38 on dist-test-slave-42z9"
I20260812 06:17:38.945123 13246 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-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:38.963749 13246 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:38.964079 13246 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:38.967806 13246 rpc_server.cc:307] RPC server started. Bound to: 127.12.239.190:45539
I20260812 06:17:38.979717 13690 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.239.190:45539 every 8 connection(s)
I20260812 06:17:38.980134 13691 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:38.982182 13691 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6dff78a4b1754d509e7cf7f834b7b1ed: Bootstrap starting.
I20260812 06:17:38.983034 13691 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 6dff78a4b1754d509e7cf7f834b7b1ed: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:38.983939 13691 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6dff78a4b1754d509e7cf7f834b7b1ed: No bootstrap required, opened a new log
I20260812 06:17:38.984297 13691 raft_consensus.cc:359] T 00000000000000000000000000000000 P 6dff78a4b1754d509e7cf7f834b7b1ed [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6dff78a4b1754d509e7cf7f834b7b1ed" member_type: VOTER }
I20260812 06:17:38.984380 13691 raft_consensus.cc:385] T 00000000000000000000000000000000 P 6dff78a4b1754d509e7cf7f834b7b1ed [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:38.984411 13691 raft_consensus.cc:740] T 00000000000000000000000000000000 P 6dff78a4b1754d509e7cf7f834b7b1ed [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6dff78a4b1754d509e7cf7f834b7b1ed, State: Initialized, Role: FOLLOWER
I20260812 06:17:38.984544 13691 consensus_queue.cc:260] T 00000000000000000000000000000000 P 6dff78a4b1754d509e7cf7f834b7b1ed [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: "6dff78a4b1754d509e7cf7f834b7b1ed" member_type: VOTER }
I20260812 06:17:38.984613 13691 raft_consensus.cc:399] T 00000000000000000000000000000000 P 6dff78a4b1754d509e7cf7f834b7b1ed [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:38.984651 13691 raft_consensus.cc:493] T 00000000000000000000000000000000 P 6dff78a4b1754d509e7cf7f834b7b1ed [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:38.984699 13691 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 6dff78a4b1754d509e7cf7f834b7b1ed [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:38.985304 13691 raft_consensus.cc:515] T 00000000000000000000000000000000 P 6dff78a4b1754d509e7cf7f834b7b1ed [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6dff78a4b1754d509e7cf7f834b7b1ed" member_type: VOTER }
I20260812 06:17:38.985425 13691 leader_election.cc:304] T 00000000000000000000000000000000 P 6dff78a4b1754d509e7cf7f834b7b1ed [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: 6dff78a4b1754d509e7cf7f834b7b1ed; no voters: 
I20260812 06:17:38.985623 13691 leader_election.cc:290] T 00000000000000000000000000000000 P 6dff78a4b1754d509e7cf7f834b7b1ed [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:38.985724 13697 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 6dff78a4b1754d509e7cf7f834b7b1ed [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:38.985913 13697 raft_consensus.cc:697] T 00000000000000000000000000000000 P 6dff78a4b1754d509e7cf7f834b7b1ed [term 1 LEADER]: Becoming Leader. State: Replica: 6dff78a4b1754d509e7cf7f834b7b1ed, State: Running, Role: LEADER
I20260812 06:17:38.985996 13691 sys_catalog.cc:565] T 00000000000000000000000000000000 P 6dff78a4b1754d509e7cf7f834b7b1ed [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:38.986143 13697 consensus_queue.cc:237] T 00000000000000000000000000000000 P 6dff78a4b1754d509e7cf7f834b7b1ed [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: "6dff78a4b1754d509e7cf7f834b7b1ed" member_type: VOTER }
I20260812 06:17:38.986548 13698 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6dff78a4b1754d509e7cf7f834b7b1ed [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "6dff78a4b1754d509e7cf7f834b7b1ed" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6dff78a4b1754d509e7cf7f834b7b1ed" member_type: VOTER } }
I20260812 06:17:38.986572 13701 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6dff78a4b1754d509e7cf7f834b7b1ed [sys.catalog]: SysCatalogTable state changed. Reason: New leader 6dff78a4b1754d509e7cf7f834b7b1ed. Latest consensus state: current_term: 1 leader_uuid: "6dff78a4b1754d509e7cf7f834b7b1ed" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6dff78a4b1754d509e7cf7f834b7b1ed" member_type: VOTER } }
I20260812 06:17:38.986717 13698 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6dff78a4b1754d509e7cf7f834b7b1ed [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:38.986733 13701 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6dff78a4b1754d509e7cf7f834b7b1ed [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:38.987219 13714 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:38.988055 13714 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:38.988255 13246 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:38.989706 13714 catalog_manager.cc:1383] Generated new cluster ID: 9ad9f8afc3504caca5a9522e23ba8fd8
I20260812 06:17:38.989759 13714 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:39.001266 13714 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:39.001814 13714 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:39.014014 13714 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 6dff78a4b1754d509e7cf7f834b7b1ed: Generated new TSK 0
I20260812 06:17:39.014153 13714 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:39.020426 13246 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:39.022122 13730 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:39.022184 13246 server_base.cc:1061] running on GCE node
W20260812 06:17:39.022228 13733 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:39.022142 13728 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:39.022497 13246 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:39.022538 13246 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:39.022557 13246 hybrid_clock.cc:648] HybridClock initialized: now 1786515459022557 us; error 0 us; skew 500 ppm
I20260812 06:17:39.023272 13246 webserver.cc:533] Webserver started at http://127.12.239.129:46465/ using document root <none> and password file <none>
I20260812 06:17:39.023399 13246 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:39.023439 13246 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:39.023494 13246 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:39.023800 13246 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/instance:
uuid: "d9294d5bc8d34abcbb5b962536360c80"
format_stamp: "Formatted at 2026-08-12 06:17:39 on dist-test-slave-42z9"
I20260812 06:17:39.025076 13246 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:39.025905 13743 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:39.026126 13246 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:17:39.026189 13246 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root
uuid: "d9294d5bc8d34abcbb5b962536360c80"
format_stamp: "Formatted at 2026-08-12 06:17:39 on dist-test-slave-42z9"
I20260812 06:17:39.026250 13246 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:39.040668 13246 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:39.040946 13246 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:39.041200 13246 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:39.041671 13246 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:39.041708 13246 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:39.041749 13246 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:39.041776 13246 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:39.045981 13246 rpc_server.cc:307] RPC server started. Bound to: 127.12.239.129:44093
I20260812 06:17:39.046038 13848 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.239.129:44093 every 8 connection(s)
I20260812 06:17:39.053434 13850 heartbeater.cc:344] Connected to a master server at 127.12.239.190:45539
I20260812 06:17:39.053536 13850 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:39.053730 13850 heartbeater.cc:507] Master 127.12.239.190:45539 requested a full tablet report, sending...
I20260812 06:17:39.054302 13617 ts_manager.cc:194] Registered new tserver with Master: d9294d5bc8d34abcbb5b962536360c80 (127.12.239.129:44093)
I20260812 06:17:39.054980 13617 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:47882
I20260812 06:17:39.055150 13246 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.00875331s
I20260812 06:17:39.061576 13617 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:47894:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:39.069648 13791 tablet_service.cc:1511] Processing CreateTablet for tablet 21359e3d214142dfac78d25446896d0e (DEFAULT_TABLE table=heavy-update-compaction-test [id=ee54d3cb5eb840f19545722af1af0364]), partition=
I20260812 06:17:39.069866 13791 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 21359e3d214142dfac78d25446896d0e. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:39.071655 13867 tablet_bootstrap.cc:492] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Bootstrap starting.
I20260812 06:17:39.072590 13867 tablet_bootstrap.cc:654] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:39.073599 13867 tablet_bootstrap.cc:492] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: No bootstrap required, opened a new log
I20260812 06:17:39.073681 13867 ts_tablet_manager.cc:1403] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:39.074064 13867 raft_consensus.cc:359] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d9294d5bc8d34abcbb5b962536360c80" member_type: VOTER last_known_addr { host: "127.12.239.129" port: 44093 } }
I20260812 06:17:39.074152 13867 raft_consensus.cc:385] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:39.074183 13867 raft_consensus.cc:740] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: d9294d5bc8d34abcbb5b962536360c80, State: Initialized, Role: FOLLOWER
I20260812 06:17:39.074321 13867 consensus_queue.cc:260] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80 [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: "d9294d5bc8d34abcbb5b962536360c80" member_type: VOTER last_known_addr { host: "127.12.239.129" port: 44093 } }
I20260812 06:17:39.074409 13867 raft_consensus.cc:399] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:39.074450 13867 raft_consensus.cc:493] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:39.074498 13867 raft_consensus.cc:3060] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:39.075300 13867 raft_consensus.cc:515] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d9294d5bc8d34abcbb5b962536360c80" member_type: VOTER last_known_addr { host: "127.12.239.129" port: 44093 } }
I20260812 06:17:39.075459 13867 leader_election.cc:304] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80 [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: d9294d5bc8d34abcbb5b962536360c80; no voters: 
I20260812 06:17:39.075641 13867 leader_election.cc:290] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:39.075731 13873 raft_consensus.cc:2804] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:39.075919 13873 raft_consensus.cc:697] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80 [term 1 LEADER]: Becoming Leader. State: Replica: d9294d5bc8d34abcbb5b962536360c80, State: Running, Role: LEADER
I20260812 06:17:39.075968 13850 heartbeater.cc:499] Master 127.12.239.190:45539 was elected leader, sending a full tablet report...
I20260812 06:17:39.076068 13873 consensus_queue.cc:237] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80 [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: "d9294d5bc8d34abcbb5b962536360c80" member_type: VOTER last_known_addr { host: "127.12.239.129" port: 44093 } }
I20260812 06:17:39.075953 13867 ts_tablet_manager.cc:1434] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:39.077292 13617 catalog_manager.cc:5719] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80 reported cstate change: term changed from 0 to 1, leader changed from <none> to d9294d5bc8d34abcbb5b962536360c80 (127.12.239.129). New cstate: current_term: 1 leader_uuid: "d9294d5bc8d34abcbb5b962536360c80" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d9294d5bc8d34abcbb5b962536360c80" member_type: VOTER last_known_addr { host: "127.12.239.129" port: 44093 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:39.130429 13246 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.050s	user 0.012s	sys 0.010s
I20260812 06:17:39.296931 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushMRSOp(21359e3d214142dfac78d25446896d0e): perf score=23.023690
I20260812 06:17:39.439810 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushMRSOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.143s	user 0.115s	sys 0.024s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":52,"dirs.run_cpu_time_us":184,"dirs.run_wall_time_us":758,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36890,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1500}
I20260812 06:17:39.440589 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling LogGCOp(21359e3d214142dfac78d25446896d0e): free 20743880 bytes of WAL
I20260812 06:17:39.440814 13754 log_reader.cc:385] T 21359e3d214142dfac78d25446896d0e: removed 2 log segments from log reader
I20260812 06:17:39.440867 13754 log.cc:1079] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/21359e3d214142dfac78d25446896d0e/wal-000000001 (ops 1-6)
I20260812 06:17:39.440907 13754 log.cc:1079] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/21359e3d214142dfac78d25446896d0e/wal-000000002 (ops 7-11)
I20260812 06:17:39.444455 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: LogGCOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.004s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:17:39.444829 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling UndoDeltaBlockGCOp(21359e3d214142dfac78d25446896d0e): 20513814 bytes on disk
I20260812 06:17:39.445230 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: UndoDeltaBlockGCOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:17:39.445792 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=2.188937
I20260812 06:17:39.460721 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5485,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":500}
I20260812 06:17:39.461287 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e): perf score=1.000000
I20260812 06:17:39.602610 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.141s	user 0.103s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":475,"lbm_read_time_us":8163,"lbm_reads_lt_1ms":460,"lbm_write_time_us":21992,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":292,"threads_started":5,"update_count":2000}
I20260812 06:17:39.603130 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=14.095187
I20260812 06:17:39.656106 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.053s	user 0.010s	sys 0.032s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19518,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:39.656654 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=2.188937
I20260812 06:17:39.666313 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.009s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3571,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:39.666841 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e): perf score=1.000000
I20260812 06:17:39.834209 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.167s	user 0.132s	sys 0.033s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":113,"lbm_read_time_us":11740,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26247,"lbm_writes_lt_1ms":543,"mutex_wait_us":56,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2500}
I20260812 06:17:39.834764 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=14.095187
I20260812 06:17:39.873908 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.039s	user 0.027s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17681,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:39.874431 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e): perf score=1.000000
I20260812 06:17:40.012717 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.138s	user 0.079s	sys 0.054s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713153,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":532,"lbm_read_time_us":8559,"lbm_reads_lt_1ms":467,"lbm_write_time_us":22936,"lbm_writes_lt_1ms":443,"mutex_wait_us":305,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18176,"update_count":2000}
I20260812 06:17:40.013366 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=11.118625
I20260812 06:17:40.047533 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.034s	user 0.019s	sys 0.013s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":14286,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:40.048245 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=2.188937
I20260812 06:17:40.065404 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.017s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5652,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:40.065845 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e): perf score=1.000000
I20260812 06:17:40.181835 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.116s	user 0.097s	sys 0.018s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713265,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1210,"lbm_read_time_us":6956,"lbm_reads_lt_1ms":464,"lbm_write_time_us":20451,"lbm_writes_lt_1ms":443,"mutex_wait_us":752,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2000}
I20260812 06:17:40.182403 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=10.126437
I20260812 06:17:40.215144 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.033s	user 0.026s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":11557,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:40.215600 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=2.188937
I20260812 06:17:40.229053 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4541,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:40.229610 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e): perf score=1.000000
I20260812 06:17:40.349409 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.120s	user 0.069s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":124,"lbm_read_time_us":6790,"lbm_reads_lt_1ms":468,"lbm_write_time_us":23705,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":2000}
I20260812 06:17:40.351564 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=10.126437
I20260812 06:17:40.392079 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.040s	user 0.016s	sys 0.022s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16385,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:40.392629 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=2.188937
I20260812 06:17:40.403896 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3909,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:40.404469 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e): perf score=1.000000
I20260812 06:17:40.524333 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.120s	user 0.091s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":261,"lbm_read_time_us":7433,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23146,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:17:40.524897 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=10.126437
I20260812 06:17:40.560160 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.035s	user 0.002s	sys 0.030s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":11962,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:40.560738 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=2.188937
I20260812 06:17:40.570544 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3713,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:40.570995 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushMRSOp(21359e3d214142dfac78d25446896d0e): perf score=1.000000
I20260812 06:17:40.597620 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushMRSOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.026s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":207,"dirs.run_wall_time_us":1370,"drs_written":1,"lbm_read_time_us":34,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1196,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29,"spinlock_wait_cycles":1280}
I20260812 06:17:40.598234 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling UndoDeltaBlockGCOp(21359e3d214142dfac78d25446896d0e): 462 bytes on disk
I20260812 06:17:40.598631 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: UndoDeltaBlockGCOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:17:40.599063 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e): perf score=1.000000
I20260812 06:17:40.739149 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.140s	user 0.099s	sys 0.030s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":674,"lbm_read_time_us":8434,"lbm_reads_lt_1ms":464,"lbm_write_time_us":20548,"lbm_writes_lt_1ms":443,"mutex_wait_us":304,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2000}
I20260812 06:17:40.739828 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling LogGCOp(21359e3d214142dfac78d25446896d0e): free 121006427 bytes of WAL
I20260812 06:17:40.740038 13754 log_reader.cc:385] T 21359e3d214142dfac78d25446896d0e: removed 12 log segments from log reader
I20260812 06:17:40.740083 13754 log.cc:1079] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/21359e3d214142dfac78d25446896d0e/wal-000000003 (ops 12-16)
I20260812 06:17:40.740116 13754 log.cc:1079] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/21359e3d214142dfac78d25446896d0e/wal-000000004 (ops 17-21)
I20260812 06:17:40.740190 13754 log.cc:1079] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/21359e3d214142dfac78d25446896d0e/wal-000000005 (ops 22-26)
I20260812 06:17:40.740229 13754 log.cc:1079] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/21359e3d214142dfac78d25446896d0e/wal-000000006 (ops 27-31)
I20260812 06:17:40.740280 13754 log.cc:1079] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/21359e3d214142dfac78d25446896d0e/wal-000000007 (ops 32-36)
I20260812 06:17:40.740312 13754 log.cc:1079] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/21359e3d214142dfac78d25446896d0e/wal-000000008 (ops 37-41)
I20260812 06:17:40.740351 13754 log.cc:1079] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/21359e3d214142dfac78d25446896d0e/wal-000000009 (ops 42-46)
I20260812 06:17:40.740381 13754 log.cc:1079] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/21359e3d214142dfac78d25446896d0e/wal-000000010 (ops 47-50)
I20260812 06:17:40.740429 13754 log.cc:1079] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/21359e3d214142dfac78d25446896d0e/wal-000000011 (ops 51-55)
I20260812 06:17:40.740463 13754 log.cc:1079] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/21359e3d214142dfac78d25446896d0e/wal-000000012 (ops 56-60)
I20260812 06:17:40.740521 13754 log.cc:1079] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/21359e3d214142dfac78d25446896d0e/wal-000000013 (ops 61-65)
I20260812 06:17:40.740553 13754 log.cc:1079] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/21359e3d214142dfac78d25446896d0e/wal-000000014 (ops 66-70)
I20260812 06:17:40.762722 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: LogGCOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.023s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:17:40.763128 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=15.087375
I20260812 06:17:40.806648 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.043s	user 0.029s	sys 0.013s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":19422,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:40.807133 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=2.188937
I20260812 06:17:40.828069 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.021s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3832,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:40.828518 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=2.188937
I20260812 06:17:40.844210 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3461,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:40.844717 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e): perf score=1.000000
I20260812 06:17:41.048861 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.204s	user 0.152s	sys 0.048s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918202,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":663,"lbm_read_time_us":15104,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34066,"lbm_writes_lt_1ms":643,"mutex_wait_us":260,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":3000}
I20260812 06:17:41.049352 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=14.095187
I20260812 06:17:41.105942 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.056s	user 0.024s	sys 0.032s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19781,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:41.106448 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=2.188937
I20260812 06:17:41.116464 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3812,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:41.116874 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e): perf score=1.000000
I20260812 06:17:41.284121 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.167s	user 0.100s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":136,"lbm_read_time_us":12369,"lbm_reads_lt_1ms":572,"lbm_write_time_us":24083,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14848,"update_count":2500}
I20260812 06:17:41.284647 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=11.118625
I20260812 06:17:41.319121 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.034s	user 0.013s	sys 0.019s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":14030,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:41.319708 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=2.188937
I20260812 06:17:41.333379 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.013s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4608,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:41.333863 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e): perf score=1.000000
I20260812 06:17:41.459441 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.125s	user 0.081s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713264,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":736,"lbm_read_time_us":8345,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23607,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:17:41.460218 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=10.126437
I20260812 06:17:41.489364 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.029s	user 0.024s	sys 0.003s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":11922,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":1500}
I20260812 06:17:41.489887 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=2.188937
I20260812 06:17:41.505700 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.016s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5673,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:41.506196 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e): perf score=1.000000
I20260812 06:17:41.632606 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.126s	user 0.101s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":296,"lbm_read_time_us":8944,"lbm_reads_lt_1ms":468,"lbm_write_time_us":24035,"lbm_writes_lt_1ms":443,"mutex_wait_us":47,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":24832,"update_count":2000}
I20260812 06:17:41.633929 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=10.126437
I20260812 06:17:41.688755 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.054s	user 0.016s	sys 0.012s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":37815,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:41.689220 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=2.188937
I20260812 06:17:41.699678 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3401,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:41.700212 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e): perf score=1.000000
I20260812 06:17:41.814009 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.114s	user 0.092s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":529,"lbm_read_time_us":7224,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21516,"lbm_writes_lt_1ms":443,"mutex_wait_us":29,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12032,"update_count":2000}
I20260812 06:17:41.814615 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=10.126437
I20260812 06:17:41.851575 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.037s	user 0.015s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":11802,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":1500}
I20260812 06:17:41.852063 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=2.188937
I20260812 06:17:41.861667 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3716,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:41.862046 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e): perf score=1.000000
I20260812 06:17:42.002800 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.141s	user 0.095s	sys 0.043s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":102,"lbm_read_time_us":9269,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21770,"lbm_writes_lt_1ms":443,"mutex_wait_us":20,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":72832,"update_count":2000}
I20260812 06:17:42.003505 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=10.126437
I20260812 06:17:42.047923 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.044s	user 0.027s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17980,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:42.048413 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=2.188937
I20260812 06:17:42.057924 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3473,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:42.058424 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushMRSOp(21359e3d214142dfac78d25446896d0e): perf score=1.000000
I20260812 06:17:42.084591 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushMRSOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.026s	user 0.024s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":40,"dirs.run_cpu_time_us":183,"dirs.run_wall_time_us":1560,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1325,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:42.085278 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling LogGCOp(21359e3d214142dfac78d25446896d0e): free 132571329 bytes of WAL
I20260812 06:17:42.085508 13754 log_reader.cc:385] T 21359e3d214142dfac78d25446896d0e: removed 13 log segments from log reader
I20260812 06:17:42.085578 13754 log.cc:1079] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/21359e3d214142dfac78d25446896d0e/wal-000000015 (ops 71-74)
I20260812 06:17:42.085625 13754 log.cc:1079] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/21359e3d214142dfac78d25446896d0e/wal-000000016 (ops 75-79)
I20260812 06:17:42.085655 13754 log.cc:1079] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/21359e3d214142dfac78d25446896d0e/wal-000000017 (ops 80-84)
I20260812 06:17:42.085682 13754 log.cc:1079] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/21359e3d214142dfac78d25446896d0e/wal-000000018 (ops 85-89)
I20260812 06:17:42.085712 13754 log.cc:1079] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/21359e3d214142dfac78d25446896d0e/wal-000000019 (ops 90-94)
I20260812 06:17:42.085744 13754 log.cc:1079] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/21359e3d214142dfac78d25446896d0e/wal-000000020 (ops 95-99)
I20260812 06:17:42.085773 13754 log.cc:1079] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/21359e3d214142dfac78d25446896d0e/wal-000000021 (ops 100-104)
I20260812 06:17:42.085801 13754 log.cc:1079] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/21359e3d214142dfac78d25446896d0e/wal-000000022 (ops 105-109)
I20260812 06:17:42.085827 13754 log.cc:1079] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/21359e3d214142dfac78d25446896d0e/wal-000000023 (ops 110-114)
I20260812 06:17:42.085857 13754 log.cc:1079] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/21359e3d214142dfac78d25446896d0e/wal-000000024 (ops 115-119)
I20260812 06:17:42.085889 13754 log.cc:1079] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/21359e3d214142dfac78d25446896d0e/wal-000000025 (ops 120-124)
I20260812 06:17:42.085919 13754 log.cc:1079] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/21359e3d214142dfac78d25446896d0e/wal-000000026 (ops 125-128)
I20260812 06:17:42.085948 13754 log.cc:1079] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/21359e3d214142dfac78d25446896d0e/wal-000000027 (ops 129-133)
I20260812 06:17:42.112577 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: LogGCOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.027s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:17:42.112989 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling UndoDeltaBlockGCOp(21359e3d214142dfac78d25446896d0e): 482 bytes on disk
I20260812 06:17:42.113404 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: UndoDeltaBlockGCOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4}
I20260812 06:17:42.114066 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=3.181125
I20260812 06:17:42.124810 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":3878,"lbm_writes_lt_1ms":113,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":550}
I20260812 06:17:42.125170 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=2.188937
I20260812 06:17:42.141619 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.016s	user 0.013s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3352,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:42.142030 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e): perf score=1.000000
I20260812 06:17:42.323760 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.182s	user 0.105s	sys 0.076s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918325,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":217,"lbm_read_time_us":12988,"lbm_reads_lt_1ms":674,"lbm_write_time_us":28032,"lbm_writes_lt_1ms":643,"mutex_wait_us":16,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":15360,"thread_start_us":68,"threads_started":1,"update_count":3000}
I20260812 06:17:42.326148 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=14.095187
I20260812 06:17:42.378841 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.053s	user 0.031s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17188,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:42.379329 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=2.188937
I20260812 06:17:42.389127 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3669,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:42.389575 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e): perf score=1.000000
I20260812 06:17:42.576072 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.186s	user 0.120s	sys 0.054s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":225,"lbm_read_time_us":11582,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29176,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2500}
I20260812 06:17:42.576567 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=14.095187
I20260812 06:17:42.622936 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.046s	user 0.028s	sys 0.007s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":15954,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:42.623493 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=2.188937
I20260812 06:17:42.633190 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3709,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:42.633735 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e): perf score=1.000000
I20260812 06:17:42.803503 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.170s	user 0.117s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":450,"lbm_read_time_us":11141,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25371,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":70912,"update_count":2500}
I20260812 06:17:42.803980 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=14.095187
I20260812 06:17:42.853941 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.050s	user 0.028s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19600,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:42.854420 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=2.188937
I20260812 06:17:42.865125 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.011s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3806,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:42.865787 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e): perf score=1.000000
I20260812 06:17:43.008977 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.143s	user 0.105s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":248,"lbm_read_time_us":9108,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27016,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2500}
I20260812 06:17:43.009519 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=11.118625
I20260812 06:17:43.043063 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.033s	user 0.023s	sys 0.008s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":13467,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:43.043624 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=2.188937
I20260812 06:17:43.059466 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.016s	user 0.006s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5027,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:43.060124 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e): perf score=1.000000
I20260812 06:17:43.177621 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.117s	user 0.089s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713262,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":510,"lbm_read_time_us":6570,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21230,"lbm_writes_lt_1ms":443,"mutex_wait_us":236,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":2000}
I20260812 06:17:43.178066 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=11.118625
I20260812 06:17:43.217372 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.039s	user 0.010s	sys 0.026s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":13709,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:43.218214 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=2.188937
I20260812 06:17:43.229941 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.011s	user 0.006s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4314,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:43.230360 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e): perf score=1.000000
I20260812 06:17:43.357102 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.127s	user 0.091s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713264,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":587,"lbm_read_time_us":6769,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21723,"lbm_writes_lt_1ms":443,"mutex_wait_us":265,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:17:43.357692 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=14.095187
I20260812 06:17:43.408185 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.050s	user 0.029s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19120,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:43.408725 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=2.188937
I20260812 06:17:43.423856 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5863,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:43.425303 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushMRSOp(21359e3d214142dfac78d25446896d0e): perf score=1.000000
I20260812 06:17:43.456388 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushMRSOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.031s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":225,"dirs.run_wall_time_us":1166,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1378,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:43.457037 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling LogGCOp(21359e3d214142dfac78d25446896d0e): free 120100580 bytes of WAL
I20260812 06:17:43.457248 13754 log_reader.cc:385] T 21359e3d214142dfac78d25446896d0e: removed 12 log segments from log reader
I20260812 06:17:43.457295 13754 log.cc:1079] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/21359e3d214142dfac78d25446896d0e/wal-000000028 (ops 134-138)
I20260812 06:17:43.457320 13754 log.cc:1079] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/21359e3d214142dfac78d25446896d0e/wal-000000029 (ops 139-143)
I20260812 06:17:43.457350 13754 log.cc:1079] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/21359e3d214142dfac78d25446896d0e/wal-000000030 (ops 144-148)
I20260812 06:17:43.457383 13754 log.cc:1079] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/21359e3d214142dfac78d25446896d0e/wal-000000031 (ops 149-152)
I20260812 06:17:43.457415 13754 log.cc:1079] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/21359e3d214142dfac78d25446896d0e/wal-000000032 (ops 153-157)
I20260812 06:17:43.457466 13754 log.cc:1079] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/21359e3d214142dfac78d25446896d0e/wal-000000033 (ops 158-162)
I20260812 06:17:43.457506 13754 log.cc:1079] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/21359e3d214142dfac78d25446896d0e/wal-000000034 (ops 163-167)
I20260812 06:17:43.457536 13754 log.cc:1079] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/21359e3d214142dfac78d25446896d0e/wal-000000035 (ops 168-172)
I20260812 06:17:43.457568 13754 log.cc:1079] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/21359e3d214142dfac78d25446896d0e/wal-000000036 (ops 173-176)
I20260812 06:17:43.457600 13754 log.cc:1079] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/21359e3d214142dfac78d25446896d0e/wal-000000037 (ops 177-181)
I20260812 06:17:43.457631 13754 log.cc:1079] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/21359e3d214142dfac78d25446896d0e/wal-000000038 (ops 182-186)
I20260812 06:17:43.457662 13754 log.cc:1079] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: Deleting log segment in path: /tmp/dist-test-taska1gxIX/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453945949-13246-0/minicluster-data/ts-0-root/wals/21359e3d214142dfac78d25446896d0e/wal-000000039 (ops 187-190)
I20260812 06:17:43.476984 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: LogGCOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.020s	user 0.000s	sys 0.016s Metrics: {}
I20260812 06:17:43.477712 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=3.181125
I20260812 06:17:43.492522 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.015s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4307783,"delete_count":0,"lbm_write_time_us":4154,"lbm_writes_lt_1ms":108,"reinsert_count":0,"update_count":525}
I20260812 06:17:43.492944 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling UndoDeltaBlockGCOp(21359e3d214142dfac78d25446896d0e): 472 bytes on disk
I20260812 06:17:43.493324 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: UndoDeltaBlockGCOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4}
I20260812 06:17:43.493892 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=2.188937
I20260812 06:17:43.502828 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.009s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3897534,"delete_count":0,"lbm_write_time_us":3322,"lbm_writes_lt_1ms":98,"reinsert_count":0,"update_count":475}
I20260812 06:17:43.503187 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e): perf score=1.000000
I20260812 06:17:43.627393 13246 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.497s	user 1.669s	sys 0.148s
I20260812 06:17:43.693457 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: MajorDeltaCompactionOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.190s	user 0.151s	sys 0.035s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020745,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":13804,"lbm_reads_lt_1ms":770,"lbm_write_time_us":32793,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3500}
I20260812 06:17:43.693990 13851 maintenance_manager.cc:419] P d9294d5bc8d34abcbb5b962536360c80: Scheduling FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e): perf score=10.126437
I20260812 06:17:43.714474 13246 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.087s	user 0.002s	sys 0.000s
I20260812 06:17:43.714934 13246 tablet_server.cc:179] TabletServer@127.12.239.129:0 shutting down...
I20260812 06:17:43.723812 13754 maintenance_manager.cc:643] P d9294d5bc8d34abcbb5b962536360c80: FlushDeltaMemStoresOp(21359e3d214142dfac78d25446896d0e) complete. Timing: real 0.030s	user 0.014s	sys 0.013s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13192,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:43.724254 13246 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:43.724452 13246 tablet_replica.cc:333] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80: stopping tablet replica
I20260812 06:17:43.724584 13246 raft_consensus.cc:2243] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:43.724725 13246 raft_consensus.cc:2272] T 21359e3d214142dfac78d25446896d0e P d9294d5bc8d34abcbb5b962536360c80 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:43.740345 13246 tablet_server.cc:196] TabletServer@127.12.239.129:0 shutdown complete.
I20260812 06:17:43.751278 13246 master.cc:562] Master@127.12.239.190:45539 shutting down...
I20260812 06:17:43.754266 13246 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 6dff78a4b1754d509e7cf7f834b7b1ed [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:43.754429 13246 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 6dff78a4b1754d509e7cf7f834b7b1ed [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:43.754498 13246 tablet_replica.cc:333] T 00000000000000000000000000000000 P 6dff78a4b1754d509e7cf7f834b7b1ed: stopping tablet replica
I20260812 06:17:43.766577 13246 master.cc:584] Master@127.12.239.190:45539 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (4896 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (9880 ms total)

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