[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:20:06.058359 23333 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.22.201.126:44081
I20260812 06:20:06.059440 23333 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:20:06.060065 23333 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:06.066824 23341 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:06.066942 23333 server_base.cc:1061] running on GCE node
W20260812 06:20:06.068418 23340 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:06.068720 23344 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:06.069264 23333 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:06.069387 23333 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:06.069442 23333 hybrid_clock.cc:648] HybridClock initialized: now 1786515606069437 us; error 0 us; skew 500 ppm
I20260812 06:20:06.071514 23333 webserver.cc:533] Webserver started at http://127.22.201.126:43571/ using document root <none> and password file <none>
I20260812 06:20:06.072093 23333 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:06.072177 23333 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:06.072440 23333 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:06.074182 23333 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/master-0-root/instance:
uuid: "49a2e32e78294a4291527c8dfe3a366e"
format_stamp: "Formatted at 2026-08-12 06:20:06 on dist-test-slave-bt4h"
I20260812 06:20:06.077826 23333 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:20:06.080363 23350 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:06.081727 23333 fs_manager.cc:730] Time spent opening block manager: real 0.003s	user 0.001s	sys 0.000s
I20260812 06:20:06.081861 23333 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/master-0-root
uuid: "49a2e32e78294a4291527c8dfe3a366e"
format_stamp: "Formatted at 2026-08-12 06:20:06 on dist-test-slave-bt4h"
I20260812 06:20:06.082026 23333 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:06.098131 23333 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:06.098915 23333 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:20:06.099113 23333 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:06.106822 23333 rpc_server.cc:307] RPC server started. Bound to: 127.22.201.126:44081
I20260812 06:20:06.106866 23406 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.22.201.126:44081 every 8 connection(s)
I20260812 06:20:06.109228 23407 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:06.114993 23407 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 49a2e32e78294a4291527c8dfe3a366e: Bootstrap starting.
I20260812 06:20:06.117429 23407 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 49a2e32e78294a4291527c8dfe3a366e: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:06.118351 23407 log.cc:826] T 00000000000000000000000000000000 P 49a2e32e78294a4291527c8dfe3a366e: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:06.120209 23407 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 49a2e32e78294a4291527c8dfe3a366e: No bootstrap required, opened a new log
I20260812 06:20:06.123090 23407 raft_consensus.cc:359] T 00000000000000000000000000000000 P 49a2e32e78294a4291527c8dfe3a366e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "49a2e32e78294a4291527c8dfe3a366e" member_type: VOTER }
I20260812 06:20:06.123275 23407 raft_consensus.cc:385] T 00000000000000000000000000000000 P 49a2e32e78294a4291527c8dfe3a366e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:06.123322 23407 raft_consensus.cc:740] T 00000000000000000000000000000000 P 49a2e32e78294a4291527c8dfe3a366e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 49a2e32e78294a4291527c8dfe3a366e, State: Initialized, Role: FOLLOWER
I20260812 06:20:06.123876 23407 consensus_queue.cc:260] T 00000000000000000000000000000000 P 49a2e32e78294a4291527c8dfe3a366e [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: "49a2e32e78294a4291527c8dfe3a366e" member_type: VOTER }
I20260812 06:20:06.124010 23407 raft_consensus.cc:399] T 00000000000000000000000000000000 P 49a2e32e78294a4291527c8dfe3a366e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:06.124051 23407 raft_consensus.cc:493] T 00000000000000000000000000000000 P 49a2e32e78294a4291527c8dfe3a366e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:06.124140 23407 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 49a2e32e78294a4291527c8dfe3a366e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:06.124951 23407 raft_consensus.cc:515] T 00000000000000000000000000000000 P 49a2e32e78294a4291527c8dfe3a366e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "49a2e32e78294a4291527c8dfe3a366e" member_type: VOTER }
I20260812 06:20:06.125363 23407 leader_election.cc:304] T 00000000000000000000000000000000 P 49a2e32e78294a4291527c8dfe3a366e [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: 49a2e32e78294a4291527c8dfe3a366e; no voters: 
I20260812 06:20:06.125663 23407 leader_election.cc:290] T 00000000000000000000000000000000 P 49a2e32e78294a4291527c8dfe3a366e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:06.125872 23410 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 49a2e32e78294a4291527c8dfe3a366e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:06.126156 23410 raft_consensus.cc:697] T 00000000000000000000000000000000 P 49a2e32e78294a4291527c8dfe3a366e [term 1 LEADER]: Becoming Leader. State: Replica: 49a2e32e78294a4291527c8dfe3a366e, State: Running, Role: LEADER
I20260812 06:20:06.126607 23410 consensus_queue.cc:237] T 00000000000000000000000000000000 P 49a2e32e78294a4291527c8dfe3a366e [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: "49a2e32e78294a4291527c8dfe3a366e" member_type: VOTER }
I20260812 06:20:06.126874 23407 sys_catalog.cc:565] T 00000000000000000000000000000000 P 49a2e32e78294a4291527c8dfe3a366e [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:06.128474 23413 sys_catalog.cc:455] T 00000000000000000000000000000000 P 49a2e32e78294a4291527c8dfe3a366e [sys.catalog]: SysCatalogTable state changed. Reason: New leader 49a2e32e78294a4291527c8dfe3a366e. Latest consensus state: current_term: 1 leader_uuid: "49a2e32e78294a4291527c8dfe3a366e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "49a2e32e78294a4291527c8dfe3a366e" member_type: VOTER } }
I20260812 06:20:06.128525 23412 sys_catalog.cc:455] T 00000000000000000000000000000000 P 49a2e32e78294a4291527c8dfe3a366e [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "49a2e32e78294a4291527c8dfe3a366e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "49a2e32e78294a4291527c8dfe3a366e" member_type: VOTER } }
I20260812 06:20:06.128623 23413 sys_catalog.cc:458] T 00000000000000000000000000000000 P 49a2e32e78294a4291527c8dfe3a366e [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:06.128623 23412 sys_catalog.cc:458] T 00000000000000000000000000000000 P 49a2e32e78294a4291527c8dfe3a366e [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:06.129024 23422 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:06.131392 23422 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:06.131706 23333 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:06.136344 23422 catalog_manager.cc:1383] Generated new cluster ID: 5d45d22ed25a4a08978a7bf0dada6f7c
I20260812 06:20:06.136422 23422 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:06.144776 23422 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:06.145665 23422 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:06.150848 23422 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 49a2e32e78294a4291527c8dfe3a366e: Generated new TSK 0
I20260812 06:20:06.151484 23422 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:06.164726 23333 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:06.167905 23432 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:06.168030 23333 server_base.cc:1061] running on GCE node
W20260812 06:20:06.168035 23435 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:06.168319 23433 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:06.168537 23333 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:06.168612 23333 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:06.168648 23333 hybrid_clock.cc:648] HybridClock initialized: now 1786515606168646 us; error 0 us; skew 500 ppm
I20260812 06:20:06.169826 23333 webserver.cc:533] Webserver started at http://127.22.201.65:34503/ using document root <none> and password file <none>
I20260812 06:20:06.170032 23333 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:06.170117 23333 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:06.170203 23333 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:06.170722 23333 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/instance:
uuid: "ea33749642174e56a0541e63709c17ef"
format_stamp: "Formatted at 2026-08-12 06:20:06 on dist-test-slave-bt4h"
I20260812 06:20:06.172356 23333 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:06.173446 23441 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:06.173738 23333 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:06.173830 23333 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root
uuid: "ea33749642174e56a0541e63709c17ef"
format_stamp: "Formatted at 2026-08-12 06:20:06 on dist-test-slave-bt4h"
I20260812 06:20:06.173919 23333 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:06.179761 23333 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:06.180192 23333 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:06.180662 23333 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:06.181581 23333 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:06.181656 23333 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:06.181730 23333 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:06.181772 23333 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:06.188843 23333 rpc_server.cc:307] RPC server started. Bound to: 127.22.201.65:36061
I20260812 06:20:06.188872 23510 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.22.201.65:36061 every 8 connection(s)
I20260812 06:20:06.199805 23511 heartbeater.cc:344] Connected to a master server at 127.22.201.126:44081
I20260812 06:20:06.200088 23511 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:06.200572 23511 heartbeater.cc:507] Master 127.22.201.126:44081 requested a full tablet report, sending...
I20260812 06:20:06.202152 23368 ts_manager.cc:194] Registered new tserver with Master: ea33749642174e56a0541e63709c17ef (127.22.201.65:36061)
I20260812 06:20:06.203094 23333 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.013566968s
I20260812 06:20:06.203624 23368 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:50248
I20260812 06:20:06.213876 23368 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:50262:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:06.228873 23472 tablet_service.cc:1511] Processing CreateTablet for tablet 5d544e2b7e0447b3a20dbee51d500a3d (DEFAULT_TABLE table=heavy-update-compaction-test [id=58f595b710754af2923ed3c50bbf3edd]), partition=
I20260812 06:20:06.229456 23472 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 5d544e2b7e0447b3a20dbee51d500a3d. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:06.232069 23523 tablet_bootstrap.cc:492] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Bootstrap starting.
I20260812 06:20:06.232990 23523 tablet_bootstrap.cc:654] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:06.234422 23523 tablet_bootstrap.cc:492] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: No bootstrap required, opened a new log
I20260812 06:20:06.234598 23523 ts_tablet_manager.cc:1403] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:20:06.235245 23523 raft_consensus.cc:359] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ea33749642174e56a0541e63709c17ef" member_type: VOTER last_known_addr { host: "127.22.201.65" port: 36061 } }
I20260812 06:20:06.235451 23523 raft_consensus.cc:385] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:06.235496 23523 raft_consensus.cc:740] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ea33749642174e56a0541e63709c17ef, State: Initialized, Role: FOLLOWER
I20260812 06:20:06.235670 23523 consensus_queue.cc:260] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef [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: "ea33749642174e56a0541e63709c17ef" member_type: VOTER last_known_addr { host: "127.22.201.65" port: 36061 } }
I20260812 06:20:06.235792 23523 raft_consensus.cc:399] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:06.235834 23523 raft_consensus.cc:493] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:06.235879 23523 raft_consensus.cc:3060] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:06.236766 23523 raft_consensus.cc:515] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ea33749642174e56a0541e63709c17ef" member_type: VOTER last_known_addr { host: "127.22.201.65" port: 36061 } }
I20260812 06:20:06.236923 23523 leader_election.cc:304] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef [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: ea33749642174e56a0541e63709c17ef; no voters: 
I20260812 06:20:06.237174 23523 leader_election.cc:290] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:06.237270 23525 raft_consensus.cc:2804] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:06.237461 23525 raft_consensus.cc:697] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef [term 1 LEADER]: Becoming Leader. State: Replica: ea33749642174e56a0541e63709c17ef, State: Running, Role: LEADER
I20260812 06:20:06.237562 23523 ts_tablet_manager.cc:1434] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:06.237608 23525 consensus_queue.cc:237] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef [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: "ea33749642174e56a0541e63709c17ef" member_type: VOTER last_known_addr { host: "127.22.201.65" port: 36061 } }
I20260812 06:20:06.238013 23511 heartbeater.cc:499] Master 127.22.201.126:44081 was elected leader, sending a full tablet report...
I20260812 06:20:06.240777 23368 catalog_manager.cc:5719] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef reported cstate change: term changed from 0 to 1, leader changed from <none> to ea33749642174e56a0541e63709c17ef (127.22.201.65). New cstate: current_term: 1 leader_uuid: "ea33749642174e56a0541e63709c17ef" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ea33749642174e56a0541e63709c17ef" member_type: VOTER last_known_addr { host: "127.22.201.65" port: 36061 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:06.322912 23333 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.073s	user 0.020s	sys 0.017s
I20260812 06:20:06.440021 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushMRSOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=15.086190
I20260812 06:20:06.614311 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushMRSOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.174s	user 0.121s	sys 0.044s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":73,"delete_count":0,"dirs.queue_time_us":36,"dirs.run_cpu_time_us":182,"dirs.run_wall_time_us":874,"drs_written":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4,"lbm_write_time_us":42436,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"spinlock_wait_cycles":2688,"update_count":1500}
I20260812 06:20:06.615461 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling LogGCOp(5d544e2b7e0447b3a20dbee51d500a3d): free 20290830 bytes of WAL
I20260812 06:20:06.615784 23447 log_reader.cc:385] T 5d544e2b7e0447b3a20dbee51d500a3d: removed 2 log segments from log reader
I20260812 06:20:06.615863 23447 log.cc:1079] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/5d544e2b7e0447b3a20dbee51d500a3d/wal-000000001 (ops 1-6)
I20260812 06:20:06.615937 23447 log.cc:1079] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/5d544e2b7e0447b3a20dbee51d500a3d/wal-000000002 (ops 7-10)
I20260812 06:20:06.620471 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: LogGCOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:20:06.620833 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=2.188937
I20260812 06:20:06.643082 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.022s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6527,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:06.643570 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling MajorDeltaCompactionOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=1.000000
I20260812 06:20:06.778051 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: MajorDeltaCompactionOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.134s	user 0.106s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1305,"lbm_read_time_us":10400,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27280,"lbm_writes_lt_1ms":443,"mutex_wait_us":307,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1536,"thread_start_us":350,"threads_started":5,"update_count":2000}
I20260812 06:20:06.778744 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=10.126437
I20260812 06:20:06.815766 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.037s	user 0.029s	sys 0.005s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15592,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:06.816337 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling UndoDeltaBlockGCOp(5d544e2b7e0447b3a20dbee51d500a3d): 12308958 bytes on disk
I20260812 06:20:06.816891 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: UndoDeltaBlockGCOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:20:06.817387 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling MajorDeltaCompactionOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=1.000000
I20260812 06:20:06.941841 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: MajorDeltaCompactionOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.124s	user 0.082s	sys 0.041s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528783,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1306,"lbm_read_time_us":8078,"lbm_reads_lt_1ms":363,"lbm_write_time_us":22969,"lbm_writes_lt_1ms":343,"mutex_wait_us":138,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":1479168,"update_count":1500}
I20260812 06:20:06.942476 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=11.118625
I20260812 06:20:06.986398 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.044s	user 0.037s	sys 0.004s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":19939,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:20:06.987043 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=2.188937
I20260812 06:20:06.999034 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4776,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:06.999483 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling MajorDeltaCompactionOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=1.000000
I20260812 06:20:07.147055 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: MajorDeltaCompactionOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.147s	user 0.112s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631304,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":158,"lbm_read_time_us":11004,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27171,"lbm_writes_lt_1ms":443,"mutex_wait_us":35,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:07.148003 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=10.126437
I20260812 06:20:07.193084 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.045s	user 0.009s	sys 0.032s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19965,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:07.193876 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=2.188937
I20260812 06:20:07.220572 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.026s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6208,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.221091 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=2.188937
I20260812 06:20:07.243105 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.022s	user 0.001s	sys 0.020s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4512,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.243813 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling MajorDeltaCompactionOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=1.000000
I20260812 06:20:07.427294 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: MajorDeltaCompactionOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.183s	user 0.134s	sys 0.048s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733843,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":308,"lbm_read_time_us":15814,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30416,"lbm_writes_lt_1ms":543,"mutex_wait_us":116,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":30976,"update_count":2500}
I20260812 06:20:07.427927 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=11.118625
I20260812 06:20:07.476893 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.048s	user 0.016s	sys 0.025s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":20596,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:20:07.477396 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=2.188937
I20260812 06:20:07.488715 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4412,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.489274 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=2.188937
I20260812 06:20:07.499840 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4003,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:07.500587 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling MajorDeltaCompactionOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=1.000000
I20260812 06:20:07.670194 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: MajorDeltaCompactionOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.169s	user 0.125s	sys 0.037s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733834,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":590,"lbm_read_time_us":11674,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30987,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2500}
I20260812 06:20:07.670923 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=11.118625
I20260812 06:20:07.715797 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.045s	user 0.024s	sys 0.019s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":19745,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:07.716305 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=2.188937
I20260812 06:20:07.729470 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.013s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4392,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.729950 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=2.188937
I20260812 06:20:07.740082 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3878,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:07.740589 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling MajorDeltaCompactionOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=1.000000
I20260812 06:20:07.901046 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: MajorDeltaCompactionOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.160s	user 0.112s	sys 0.048s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733835,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":336,"lbm_read_time_us":13539,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32593,"lbm_writes_lt_1ms":543,"mutex_wait_us":33,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18304,"update_count":2500}
I20260812 06:20:07.901707 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=10.126437
I20260812 06:20:07.949792 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.048s	user 0.017s	sys 0.028s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":20998,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":1500}
I20260812 06:20:07.950631 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=2.188937
I20260812 06:20:07.967145 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.016s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6158,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:07.967649 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushMRSOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=1.000000
I20260812 06:20:08.010174 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushMRSOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.042s	user 0.025s	sys 0.004s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":81,"dirs.run_cpu_time_us":308,"dirs.run_wall_time_us":1798,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2573,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:08.011296 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=3.181125
I20260812 06:20:08.024461 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":4557,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:08.024960 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling LogGCOp(5d544e2b7e0447b3a20dbee51d500a3d): free 121006377 bytes of WAL
I20260812 06:20:08.025192 23447 log_reader.cc:385] T 5d544e2b7e0447b3a20dbee51d500a3d: removed 12 log segments from log reader
I20260812 06:20:08.025249 23447 log.cc:1079] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/5d544e2b7e0447b3a20dbee51d500a3d/wal-000000003 (ops 11-15)
I20260812 06:20:08.025300 23447 log.cc:1079] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/5d544e2b7e0447b3a20dbee51d500a3d/wal-000000004 (ops 16-20)
I20260812 06:20:08.025354 23447 log.cc:1079] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/5d544e2b7e0447b3a20dbee51d500a3d/wal-000000005 (ops 21-25)
I20260812 06:20:08.025399 23447 log.cc:1079] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/5d544e2b7e0447b3a20dbee51d500a3d/wal-000000006 (ops 26-30)
I20260812 06:20:08.025435 23447 log.cc:1079] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/5d544e2b7e0447b3a20dbee51d500a3d/wal-000000007 (ops 31-34)
I20260812 06:20:08.025473 23447 log.cc:1079] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/5d544e2b7e0447b3a20dbee51d500a3d/wal-000000008 (ops 35-39)
I20260812 06:20:08.025512 23447 log.cc:1079] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/5d544e2b7e0447b3a20dbee51d500a3d/wal-000000009 (ops 40-44)
I20260812 06:20:08.025552 23447 log.cc:1079] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/5d544e2b7e0447b3a20dbee51d500a3d/wal-000000010 (ops 45-49)
I20260812 06:20:08.025592 23447 log.cc:1079] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/5d544e2b7e0447b3a20dbee51d500a3d/wal-000000011 (ops 50-54)
I20260812 06:20:08.025628 23447 log.cc:1079] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/5d544e2b7e0447b3a20dbee51d500a3d/wal-000000012 (ops 55-59)
I20260812 06:20:08.025674 23447 log.cc:1079] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/5d544e2b7e0447b3a20dbee51d500a3d/wal-000000013 (ops 60-64)
I20260812 06:20:08.025712 23447 log.cc:1079] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/5d544e2b7e0447b3a20dbee51d500a3d/wal-000000014 (ops 65-69)
I20260812 06:20:08.054193 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: LogGCOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.029s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:20:08.054682 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling UndoDeltaBlockGCOp(5d544e2b7e0447b3a20dbee51d500a3d): 483 bytes on disk
I20260812 06:20:08.055193 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: UndoDeltaBlockGCOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:20:08.055702 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=2.188937
I20260812 06:20:08.069484 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.014s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4020609,"delete_count":0,"lbm_write_time_us":4444,"lbm_writes_lt_1ms":101,"reinsert_count":0,"update_count":490}
I20260812 06:20:08.069988 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=2.188937
I20260812 06:20:08.093991 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.024s	user 0.006s	sys 0.014s Metrics: {"bytes_written":3774459,"delete_count":0,"lbm_write_time_us":4591,"lbm_writes_lt_1ms":95,"reinsert_count":0,"update_count":460}
I20260812 06:20:08.094697 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling MajorDeltaCompactionOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=1.000000
I20260812 06:20:08.338253 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: MajorDeltaCompactionOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.243s	user 0.178s	sys 0.065s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32938897,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":549,"lbm_read_time_us":18670,"lbm_reads_lt_1ms":775,"lbm_write_time_us":42278,"lbm_writes_lt_1ms":743,"mutex_wait_us":40,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":15360,"thread_start_us":77,"threads_started":1,"update_count":3500}
I20260812 06:20:08.338971 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=14.095187
I20260812 06:20:08.409891 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.071s	user 0.033s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26729,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:08.410574 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=3.181125
I20260812 06:20:08.428598 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.018s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7460,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:08.429144 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=2.188937
I20260812 06:20:08.439425 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3891,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:08.440153 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling MajorDeltaCompactionOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=1.000000
I20260812 06:20:08.641708 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: MajorDeltaCompactionOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.201s	user 0.119s	sys 0.082s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836241,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":189,"lbm_read_time_us":15815,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32737,"lbm_writes_lt_1ms":643,"mutex_wait_us":44,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":40320,"update_count":3000}
I20260812 06:20:08.642376 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=14.095187
I20260812 06:20:08.696574 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.054s	user 0.027s	sys 0.025s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23163,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:08.697147 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=2.188937
I20260812 06:20:08.710772 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4610,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:08.711311 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling MajorDeltaCompactionOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=1.000000
I20260812 06:20:08.885594 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: MajorDeltaCompactionOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.174s	user 0.107s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":277,"lbm_read_time_us":14007,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28362,"lbm_writes_lt_1ms":543,"mutex_wait_us":70,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:08.886252 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=14.095187
I20260812 06:20:08.949381 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.063s	user 0.027s	sys 0.032s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":23784,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:08.949961 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=2.188937
I20260812 06:20:08.961292 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4343,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:08.961836 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling MajorDeltaCompactionOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=1.000000
I20260812 06:20:09.160126 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: MajorDeltaCompactionOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.198s	user 0.129s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733727,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":221,"lbm_read_time_us":13644,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34494,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8576,"update_count":2500}
I20260812 06:20:09.160830 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=14.095187
I20260812 06:20:09.221073 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.060s	user 0.020s	sys 0.036s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22552,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:09.221637 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=2.188937
I20260812 06:20:09.232868 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4315,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:09.233433 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling MajorDeltaCompactionOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=1.000000
I20260812 06:20:09.421958 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: MajorDeltaCompactionOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.188s	user 0.126s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":239,"lbm_read_time_us":14313,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29510,"lbm_writes_lt_1ms":543,"mutex_wait_us":60,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":23936,"update_count":2500}
I20260812 06:20:09.422645 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=14.095187
I20260812 06:20:09.475214 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.052s	user 0.023s	sys 0.028s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":23803,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:09.475826 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=2.188937
I20260812 06:20:09.497366 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.021s	user 0.007s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4781,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:09.497925 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushMRSOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=1.000000
I20260812 06:20:09.538156 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushMRSOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.040s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":237,"dirs.run_wall_time_us":1183,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1997,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:09.539376 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling LogGCOp(5d544e2b7e0447b3a20dbee51d500a3d): free 112239373 bytes of WAL
I20260812 06:20:09.539678 23447 log_reader.cc:385] T 5d544e2b7e0447b3a20dbee51d500a3d: removed 11 log segments from log reader
I20260812 06:20:09.539746 23447 log.cc:1079] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/5d544e2b7e0447b3a20dbee51d500a3d/wal-000000015 (ops 70-74)
I20260812 06:20:09.539803 23447 log.cc:1079] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/5d544e2b7e0447b3a20dbee51d500a3d/wal-000000016 (ops 75-79)
I20260812 06:20:09.539856 23447 log.cc:1079] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/5d544e2b7e0447b3a20dbee51d500a3d/wal-000000017 (ops 80-84)
I20260812 06:20:09.539898 23447 log.cc:1079] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/5d544e2b7e0447b3a20dbee51d500a3d/wal-000000018 (ops 85-88)
I20260812 06:20:09.539938 23447 log.cc:1079] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/5d544e2b7e0447b3a20dbee51d500a3d/wal-000000019 (ops 89-93)
I20260812 06:20:09.539996 23447 log.cc:1079] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/5d544e2b7e0447b3a20dbee51d500a3d/wal-000000020 (ops 94-98)
I20260812 06:20:09.540045 23447 log.cc:1079] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/5d544e2b7e0447b3a20dbee51d500a3d/wal-000000021 (ops 99-103)
I20260812 06:20:09.540079 23447 log.cc:1079] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/5d544e2b7e0447b3a20dbee51d500a3d/wal-000000022 (ops 104-108)
I20260812 06:20:09.540115 23447 log.cc:1079] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/5d544e2b7e0447b3a20dbee51d500a3d/wal-000000023 (ops 109-113)
I20260812 06:20:09.540154 23447 log.cc:1079] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/5d544e2b7e0447b3a20dbee51d500a3d/wal-000000024 (ops 114-118)
I20260812 06:20:09.540194 23447 log.cc:1079] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/5d544e2b7e0447b3a20dbee51d500a3d/wal-000000025 (ops 119-123)
I20260812 06:20:09.572762 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: LogGCOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.033s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:20:09.573221 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=6.157687
I20260812 06:20:09.601821 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.028s	user 0.017s	sys 0.005s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10104,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:20:09.602324 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling LogGCOp(5d544e2b7e0447b3a20dbee51d500a3d): free 12017932 bytes of WAL
I20260812 06:20:09.602638 23447 log_reader.cc:385] T 5d544e2b7e0447b3a20dbee51d500a3d: removed 1 log segments from log reader
I20260812 06:20:09.602716 23447 log.cc:1079] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/5d544e2b7e0447b3a20dbee51d500a3d/wal-000000026 (ops 124-128)
I20260812 06:20:09.606154 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: LogGCOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.004s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:20:09.606536 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling UndoDeltaBlockGCOp(5d544e2b7e0447b3a20dbee51d500a3d): 447 bytes on disk
I20260812 06:20:09.607136 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: UndoDeltaBlockGCOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":80,"lbm_reads_lt_1ms":4}
I20260812 06:20:09.607715 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling MajorDeltaCompactionOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=1.000000
I20260812 06:20:09.846853 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: MajorDeltaCompactionOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.239s	user 0.157s	sys 0.080s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32938672,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":2264,"lbm_read_time_us":16490,"lbm_reads_lt_1ms":765,"lbm_write_time_us":41317,"lbm_writes_lt_1ms":743,"mutex_wait_us":1605,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":17024,"thread_start_us":98,"threads_started":1,"update_count":3500}
I20260812 06:20:09.848133 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=18.063937
I20260812 06:20:09.929133 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.081s	user 0.051s	sys 0.024s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":33962,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:20:09.929811 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=2.188937
I20260812 06:20:09.943048 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.013s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102660,"delete_count":0,"lbm_write_time_us":5041,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:09.943540 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling MajorDeltaCompactionOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=1.000000
I20260812 06:20:10.160890 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: MajorDeltaCompactionOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.217s	user 0.148s	sys 0.059s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28836141,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1697,"dirs.run_cpu_time_us":3720,"dirs.run_wall_time_us":24638,"lbm_read_time_us":14772,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35518,"lbm_writes_lt_1ms":643,"mutex_wait_us":1009,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":3000}
I20260812 06:20:10.161466 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=15.087375
I20260812 06:20:10.215224 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.054s	user 0.025s	sys 0.028s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":24226,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:20:10.215884 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=2.188937
I20260812 06:20:10.231685 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.016s	user 0.011s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5080,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:10.232200 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling MajorDeltaCompactionOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=1.000000
I20260812 06:20:10.409857 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: MajorDeltaCompactionOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.177s	user 0.125s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733710,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":553,"lbm_read_time_us":14024,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30057,"lbm_writes_lt_1ms":543,"mutex_wait_us":3,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13184,"update_count":2500}
I20260812 06:20:10.410923 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=14.095187
I20260812 06:20:10.470484 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.059s	user 0.032s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25564,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:10.471141 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=3.181125
I20260812 06:20:10.490245 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.019s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":5698,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:10.490763 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=2.188937
I20260812 06:20:10.500815 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3831,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:10.501312 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling MajorDeltaCompactionOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=1.000000
I20260812 06:20:10.713173 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: MajorDeltaCompactionOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.212s	user 0.151s	sys 0.059s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836241,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":710,"lbm_read_time_us":16729,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34077,"lbm_writes_lt_1ms":643,"mutex_wait_us":51,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3000}
I20260812 06:20:10.713742 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=15.087375
I20260812 06:20:10.762111 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.048s	user 0.025s	sys 0.020s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":22080,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:20:10.762790 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=2.188937
I20260812 06:20:10.776667 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3856509,"delete_count":0,"lbm_write_time_us":5411,"lbm_writes_lt_1ms":97,"reinsert_count":0,"update_count":470}
I20260812 06:20:10.777128 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling MajorDeltaCompactionOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=1.000000
I20260812 06:20:10.943329 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: MajorDeltaCompactionOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.166s	user 0.122s	sys 0.044s Metrics: {"cfile_cache_miss":536,"cfile_cache_miss_bytes":24897814,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":656,"lbm_read_time_us":12500,"lbm_reads_lt_1ms":568,"lbm_write_time_us":28588,"lbm_writes_lt_1ms":547,"mutex_wait_us":324,"peak_mem_usage":63280040,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2520}
I20260812 06:20:10.944048 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=14.095187
I20260812 06:20:10.996969 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.053s	user 0.029s	sys 0.019s Metrics: {"bytes_written":16245811,"delete_count":0,"lbm_write_time_us":22438,"lbm_writes_lt_1ms":399,"reinsert_count":0,"update_count":1980}
I20260812 06:20:10.997511 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=2.188937
I20260812 06:20:11.020874 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.023s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4674,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:11.021353 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=2.188937
I20260812 06:20:11.032516 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4443,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:11.033054 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushMRSOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=1.000000
I20260812 06:20:11.068164 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushMRSOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.035s	user 0.025s	sys 0.001s Metrics: {"bytes_written":1234475,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":243,"dirs.run_wall_time_us":1338,"drs_written":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1772,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:11.068846 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling LogGCOp(5d544e2b7e0447b3a20dbee51d500a3d): free 121006648 bytes of WAL
I20260812 06:20:11.069084 23447 log_reader.cc:385] T 5d544e2b7e0447b3a20dbee51d500a3d: removed 12 log segments from log reader
I20260812 06:20:11.069128 23447 log.cc:1079] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/5d544e2b7e0447b3a20dbee51d500a3d/wal-000000027 (ops 129-133)
I20260812 06:20:11.069156 23447 log.cc:1079] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/5d544e2b7e0447b3a20dbee51d500a3d/wal-000000028 (ops 134-138)
I20260812 06:20:11.069226 23447 log.cc:1079] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/5d544e2b7e0447b3a20dbee51d500a3d/wal-000000029 (ops 139-143)
I20260812 06:20:11.069270 23447 log.cc:1079] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/5d544e2b7e0447b3a20dbee51d500a3d/wal-000000030 (ops 144-148)
I20260812 06:20:11.069310 23447 log.cc:1079] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/5d544e2b7e0447b3a20dbee51d500a3d/wal-000000031 (ops 149-153)
I20260812 06:20:11.069368 23447 log.cc:1079] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/5d544e2b7e0447b3a20dbee51d500a3d/wal-000000032 (ops 154-158)
I20260812 06:20:11.069407 23447 log.cc:1079] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/5d544e2b7e0447b3a20dbee51d500a3d/wal-000000033 (ops 159-162)
I20260812 06:20:11.069445 23447 log.cc:1079] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/5d544e2b7e0447b3a20dbee51d500a3d/wal-000000034 (ops 163-167)
I20260812 06:20:11.069482 23447 log.cc:1079] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/5d544e2b7e0447b3a20dbee51d500a3d/wal-000000035 (ops 168-172)
I20260812 06:20:11.069521 23447 log.cc:1079] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/5d544e2b7e0447b3a20dbee51d500a3d/wal-000000036 (ops 173-177)
I20260812 06:20:11.069558 23447 log.cc:1079] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/5d544e2b7e0447b3a20dbee51d500a3d/wal-000000037 (ops 178-182)
I20260812 06:20:11.069600 23447 log.cc:1079] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/5d544e2b7e0447b3a20dbee51d500a3d/wal-000000038 (ops 183-187)
I20260812 06:20:11.099911 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: LogGCOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.031s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:20:11.100932 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=3.181125
I20260812 06:20:11.116135 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.015s	user 0.000s	sys 0.011s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":4946,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:11.116598 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=2.188937
I20260812 06:20:11.126744 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3903,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:11.127215 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling UndoDeltaBlockGCOp(5d544e2b7e0447b3a20dbee51d500a3d): 473 bytes on disk
I20260812 06:20:11.127657 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: UndoDeltaBlockGCOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:20:11.128293 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling MajorDeltaCompactionOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=1.000000
I20260812 06:20:11.387463 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: MajorDeltaCompactionOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.259s	user 0.192s	sys 0.059s Metrics: {"cfile_cache_miss":831,"cfile_cache_miss_bytes":36877211,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":501,"lbm_read_time_us":19366,"lbm_reads_lt_1ms":871,"lbm_write_time_us":47922,"lbm_writes_lt_1ms":839,"mutex_wait_us":31,"peak_mem_usage":99191092,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":77,"threads_started":1,"update_count":3980}
I20260812 06:20:11.388242 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=18.063937
I20260812 06:20:11.447408 23333 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.124s	user 1.844s	sys 0.143s
I20260812 06:20:11.450702 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.062s	user 0.037s	sys 0.016s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":24040,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:11.451159 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=2.188937
I20260812 06:20:11.464258 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: FlushDeltaMemStoresOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.013s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5355,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":500}
I20260812 06:20:11.464761 23512 maintenance_manager.cc:419] P ea33749642174e56a0541e63709c17ef: Scheduling MajorDeltaCompactionOp(5d544e2b7e0447b3a20dbee51d500a3d): perf score=1.000000
I20260812 06:20:11.499495 23333 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.052s	user 0.003s	sys 0.000s
I20260812 06:20:11.500191 23333 tablet_server.cc:179] TabletServer@127.22.201.65:0 shutting down...
I20260812 06:20:11.607231 23447 maintenance_manager.cc:643] P ea33749642174e56a0541e63709c17ef: MajorDeltaCompactionOp(5d544e2b7e0447b3a20dbee51d500a3d) complete. Timing: real 0.142s	user 0.118s	sys 0.025s Metrics: {"cfile_cache_hit":440,"cfile_cache_hit_bytes":18010511,"cfile_cache_miss":192,"cfile_cache_miss_bytes":10825627,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":267,"lbm_read_time_us":4773,"lbm_reads_lt_1ms":224,"lbm_write_time_us":30742,"lbm_writes_lt_1ms":643,"mutex_wait_us":66,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3000}
I20260812 06:20:11.608059 23333 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:11.608523 23333 tablet_replica.cc:333] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef: stopping tablet replica
I20260812 06:20:11.608793 23333 raft_consensus.cc:2243] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:11.609058 23333 raft_consensus.cc:2272] T 5d544e2b7e0447b3a20dbee51d500a3d P ea33749642174e56a0541e63709c17ef [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:11.625352 23333 tablet_server.cc:196] TabletServer@127.22.201.65:0 shutdown complete.
I20260812 06:20:11.662078 23333 master.cc:562] Master@127.22.201.126:44081 shutting down...
I20260812 06:20:11.666163 23333 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 49a2e32e78294a4291527c8dfe3a366e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:11.666342 23333 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 49a2e32e78294a4291527c8dfe3a366e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:11.666397 23333 tablet_replica.cc:333] T 00000000000000000000000000000000 P 49a2e32e78294a4291527c8dfe3a366e: stopping tablet replica
I20260812 06:20:11.678970 23333 master.cc:584] Master@127.22.201.126:44081 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5717 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:11.775372 23333 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.22.201.126:42787
I20260812 06:20:11.775718 23333 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:11.777729 23542 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:11.777796 23545 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:11.777853 23543 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:11.777976 23333 server_base.cc:1061] running on GCE node
I20260812 06:20:11.778182 23333 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:11.778223 23333 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:11.778237 23333 hybrid_clock.cc:648] HybridClock initialized: now 1786515611778238 us; error 0 us; skew 500 ppm
I20260812 06:20:11.779168 23333 webserver.cc:533] Webserver started at http://127.22.201.126:35177/ using document root <none> and password file <none>
I20260812 06:20:11.779376 23333 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:11.779422 23333 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:11.779522 23333 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:11.779929 23333 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/master-0-root/instance:
uuid: "1d835205c7cb4abaac13740dd07eec8d"
format_stamp: "Formatted at 2026-08-12 06:20:11 on dist-test-slave-bt4h"
I20260812 06:20:11.781498 23333 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:11.782439 23550 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:11.782799 23333 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:11.782871 23333 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/master-0-root
uuid: "1d835205c7cb4abaac13740dd07eec8d"
format_stamp: "Formatted at 2026-08-12 06:20:11 on dist-test-slave-bt4h"
I20260812 06:20:11.782932 23333 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:11.788352 23333 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:11.788705 23333 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:11.792861 23333 rpc_server.cc:307] RPC server started. Bound to: 127.22.201.126:42787
I20260812 06:20:11.802376 23607 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:11.804337 23606 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.22.201.126:42787 every 8 connection(s)
I20260812 06:20:11.805572 23607 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1d835205c7cb4abaac13740dd07eec8d: Bootstrap starting.
I20260812 06:20:11.806427 23607 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 1d835205c7cb4abaac13740dd07eec8d: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:11.807561 23607 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1d835205c7cb4abaac13740dd07eec8d: No bootstrap required, opened a new log
I20260812 06:20:11.807986 23607 raft_consensus.cc:359] T 00000000000000000000000000000000 P 1d835205c7cb4abaac13740dd07eec8d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1d835205c7cb4abaac13740dd07eec8d" member_type: VOTER }
I20260812 06:20:11.808072 23607 raft_consensus.cc:385] T 00000000000000000000000000000000 P 1d835205c7cb4abaac13740dd07eec8d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:11.808128 23607 raft_consensus.cc:740] T 00000000000000000000000000000000 P 1d835205c7cb4abaac13740dd07eec8d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1d835205c7cb4abaac13740dd07eec8d, State: Initialized, Role: FOLLOWER
I20260812 06:20:11.808319 23607 consensus_queue.cc:260] T 00000000000000000000000000000000 P 1d835205c7cb4abaac13740dd07eec8d [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: "1d835205c7cb4abaac13740dd07eec8d" member_type: VOTER }
I20260812 06:20:11.808393 23607 raft_consensus.cc:399] T 00000000000000000000000000000000 P 1d835205c7cb4abaac13740dd07eec8d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:11.808463 23607 raft_consensus.cc:493] T 00000000000000000000000000000000 P 1d835205c7cb4abaac13740dd07eec8d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:11.808540 23607 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 1d835205c7cb4abaac13740dd07eec8d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:11.809231 23607 raft_consensus.cc:515] T 00000000000000000000000000000000 P 1d835205c7cb4abaac13740dd07eec8d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1d835205c7cb4abaac13740dd07eec8d" member_type: VOTER }
I20260812 06:20:11.809388 23607 leader_election.cc:304] T 00000000000000000000000000000000 P 1d835205c7cb4abaac13740dd07eec8d [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: 1d835205c7cb4abaac13740dd07eec8d; no voters: 
I20260812 06:20:11.809621 23607 leader_election.cc:290] T 00000000000000000000000000000000 P 1d835205c7cb4abaac13740dd07eec8d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:11.809762 23610 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 1d835205c7cb4abaac13740dd07eec8d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:11.810003 23610 raft_consensus.cc:697] T 00000000000000000000000000000000 P 1d835205c7cb4abaac13740dd07eec8d [term 1 LEADER]: Becoming Leader. State: Replica: 1d835205c7cb4abaac13740dd07eec8d, State: Running, Role: LEADER
I20260812 06:20:11.810076 23607 sys_catalog.cc:565] T 00000000000000000000000000000000 P 1d835205c7cb4abaac13740dd07eec8d [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:11.810175 23610 consensus_queue.cc:237] T 00000000000000000000000000000000 P 1d835205c7cb4abaac13740dd07eec8d [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: "1d835205c7cb4abaac13740dd07eec8d" member_type: VOTER }
I20260812 06:20:11.810694 23612 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1d835205c7cb4abaac13740dd07eec8d [sys.catalog]: SysCatalogTable state changed. Reason: New leader 1d835205c7cb4abaac13740dd07eec8d. Latest consensus state: current_term: 1 leader_uuid: "1d835205c7cb4abaac13740dd07eec8d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1d835205c7cb4abaac13740dd07eec8d" member_type: VOTER } }
I20260812 06:20:11.810810 23612 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1d835205c7cb4abaac13740dd07eec8d [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:11.810680 23611 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1d835205c7cb4abaac13740dd07eec8d [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "1d835205c7cb4abaac13740dd07eec8d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1d835205c7cb4abaac13740dd07eec8d" member_type: VOTER } }
I20260812 06:20:11.811023 23611 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1d835205c7cb4abaac13740dd07eec8d [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:11.812031 23333 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:20:11.812539 23627 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 1d835205c7cb4abaac13740dd07eec8d: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:20:11.812602 23627 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:20:11.812688 23617 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:11.813354 23617 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:11.815233 23617 catalog_manager.cc:1383] Generated new cluster ID: a9e92171d4404924833322ed2886d042
I20260812 06:20:11.815305 23617 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:11.833084 23617 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:11.833702 23617 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:11.849860 23617 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 1d835205c7cb4abaac13740dd07eec8d: Generated new TSK 0
I20260812 06:20:11.850063 23617 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:11.876724 23333 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:11.878902 23630 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:11.878944 23333 server_base.cc:1061] running on GCE node
W20260812 06:20:11.879006 23632 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:11.878942 23629 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:11.879302 23333 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:11.879349 23333 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:11.879365 23333 hybrid_clock.cc:648] HybridClock initialized: now 1786515611879366 us; error 0 us; skew 500 ppm
I20260812 06:20:11.880275 23333 webserver.cc:533] Webserver started at http://127.22.201.65:40045/ using document root <none> and password file <none>
I20260812 06:20:11.880462 23333 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:11.880511 23333 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:11.880625 23333 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:11.881045 23333 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/instance:
uuid: "bee236fb7a71469a9d1086c6a09e6d25"
format_stamp: "Formatted at 2026-08-12 06:20:11 on dist-test-slave-bt4h"
I20260812 06:20:11.882619 23333 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:11.883599 23638 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:11.883884 23333 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:11.883972 23333 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root
uuid: "bee236fb7a71469a9d1086c6a09e6d25"
format_stamp: "Formatted at 2026-08-12 06:20:11 on dist-test-slave-bt4h"
I20260812 06:20:11.884050 23333 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:11.895977 23333 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:11.896349 23333 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:11.896629 23333 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:11.897150 23333 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:11.897192 23333 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:11.897231 23333 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:11.897246 23333 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:11.901674 23333 rpc_server.cc:307] RPC server started. Bound to: 127.22.201.65:36889
I20260812 06:20:11.904065 23706 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.22.201.65:36889 every 8 connection(s)
I20260812 06:20:11.912472 23707 heartbeater.cc:344] Connected to a master server at 127.22.201.126:42787
I20260812 06:20:11.912622 23707 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:11.912887 23707 heartbeater.cc:507] Master 127.22.201.126:42787 requested a full tablet report, sending...
I20260812 06:20:11.913585 23570 ts_manager.cc:194] Registered new tserver with Master: bee236fb7a71469a9d1086c6a09e6d25 (127.22.201.65:36889)
I20260812 06:20:11.913800 23333 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011118888s
I20260812 06:20:11.914371 23570 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:50348
I20260812 06:20:11.921404 23570 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:50362:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:11.930337 23669 tablet_service.cc:1511] Processing CreateTablet for tablet 1537d813c8b142d996c38f03ba2843c1 (DEFAULT_TABLE table=heavy-update-compaction-test [id=4647c6082fde47deab604a75e3ae26fa]), partition=
I20260812 06:20:11.930673 23669 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 1537d813c8b142d996c38f03ba2843c1. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:11.932657 23722 tablet_bootstrap.cc:492] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Bootstrap starting.
I20260812 06:20:11.933573 23722 tablet_bootstrap.cc:654] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:11.934762 23722 tablet_bootstrap.cc:492] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: No bootstrap required, opened a new log
I20260812 06:20:11.934844 23722 ts_tablet_manager.cc:1403] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:11.935271 23722 raft_consensus.cc:359] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bee236fb7a71469a9d1086c6a09e6d25" member_type: VOTER last_known_addr { host: "127.22.201.65" port: 36889 } }
I20260812 06:20:11.935359 23722 raft_consensus.cc:385] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:11.935382 23722 raft_consensus.cc:740] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: bee236fb7a71469a9d1086c6a09e6d25, State: Initialized, Role: FOLLOWER
I20260812 06:20:11.935575 23722 consensus_queue.cc:260] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25 [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: "bee236fb7a71469a9d1086c6a09e6d25" member_type: VOTER last_known_addr { host: "127.22.201.65" port: 36889 } }
I20260812 06:20:11.935681 23722 raft_consensus.cc:399] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:11.935734 23722 raft_consensus.cc:493] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:11.935812 23722 raft_consensus.cc:3060] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:11.936652 23722 raft_consensus.cc:515] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bee236fb7a71469a9d1086c6a09e6d25" member_type: VOTER last_known_addr { host: "127.22.201.65" port: 36889 } }
I20260812 06:20:11.936815 23722 leader_election.cc:304] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25 [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: bee236fb7a71469a9d1086c6a09e6d25; no voters: 
I20260812 06:20:11.937027 23722 leader_election.cc:290] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:11.937160 23724 raft_consensus.cc:2804] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:11.937379 23722 ts_tablet_manager.cc:1434] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:20:11.937418 23724 raft_consensus.cc:697] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25 [term 1 LEADER]: Becoming Leader. State: Replica: bee236fb7a71469a9d1086c6a09e6d25, State: Running, Role: LEADER
I20260812 06:20:11.937419 23707 heartbeater.cc:499] Master 127.22.201.126:42787 was elected leader, sending a full tablet report...
I20260812 06:20:11.937592 23724 consensus_queue.cc:237] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25 [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: "bee236fb7a71469a9d1086c6a09e6d25" member_type: VOTER last_known_addr { host: "127.22.201.65" port: 36889 } }
I20260812 06:20:11.938876 23570 catalog_manager.cc:5719] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25 reported cstate change: term changed from 0 to 1, leader changed from <none> to bee236fb7a71469a9d1086c6a09e6d25 (127.22.201.65). New cstate: current_term: 1 leader_uuid: "bee236fb7a71469a9d1086c6a09e6d25" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bee236fb7a71469a9d1086c6a09e6d25" member_type: VOTER last_known_addr { host: "127.22.201.65" port: 36889 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:12.003100 23333 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.057s	user 0.016s	sys 0.008s
I20260812 06:20:12.154654 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushMRSOp(1537d813c8b142d996c38f03ba2843c1): perf score=19.054940
I20260812 06:20:12.322304 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushMRSOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.167s	user 0.144s	sys 0.020s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":215,"dirs.run_wall_time_us":800,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44526,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":3840,"update_count":1500}
I20260812 06:20:12.323271 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling LogGCOp(1537d813c8b142d996c38f03ba2843c1): free 20743880 bytes of WAL
I20260812 06:20:12.323578 23644 log_reader.cc:385] T 1537d813c8b142d996c38f03ba2843c1: removed 2 log segments from log reader
I20260812 06:20:12.323653 23644 log.cc:1079] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/1537d813c8b142d996c38f03ba2843c1/wal-000000001 (ops 1-6)
I20260812 06:20:12.323710 23644 log.cc:1079] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/1537d813c8b142d996c38f03ba2843c1/wal-000000002 (ops 7-11)
I20260812 06:20:12.329527 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: LogGCOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.006s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:20:12.330061 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=2.188937
I20260812 06:20:12.343567 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5290,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:12.344074 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling UndoDeltaBlockGCOp(1537d813c8b142d996c38f03ba2843c1): 16411395 bytes on disk
I20260812 06:20:12.344853 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: UndoDeltaBlockGCOp(1537d813c8b142d996c38f03ba2843c1) 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:20:12.345480 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling MajorDeltaCompactionOp(1537d813c8b142d996c38f03ba2843c1): perf score=1.000000
I20260812 06:20:12.504896 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: MajorDeltaCompactionOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.159s	user 0.095s	sys 0.064s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1026,"lbm_read_time_us":12803,"lbm_reads_lt_1ms":464,"lbm_write_time_us":30692,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":349,"threads_started":5,"update_count":2000}
I20260812 06:20:12.505697 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=10.126437
I20260812 06:20:12.551939 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.046s	user 0.020s	sys 0.022s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16448,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:12.552551 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=2.188937
I20260812 06:20:12.565513 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.013s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4903,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:12.566148 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling MajorDeltaCompactionOp(1537d813c8b142d996c38f03ba2843c1): perf score=1.000000
I20260812 06:20:12.725399 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: MajorDeltaCompactionOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.159s	user 0.117s	sys 0.037s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":210,"lbm_read_time_us":12234,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25530,"lbm_writes_lt_1ms":443,"mutex_wait_us":67,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:20:12.726127 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=11.118625
I20260812 06:20:12.762756 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.036s	user 0.036s	sys 0.000s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":15922,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:12.763283 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=2.188937
I20260812 06:20:12.786695 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.023s	user 0.011s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4622,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:12.787189 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=2.188937
I20260812 06:20:12.798013 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4419,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:12.798470 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling MajorDeltaCompactionOp(1537d813c8b142d996c38f03ba2843c1): perf score=1.000000
I20260812 06:20:12.994272 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: MajorDeltaCompactionOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.196s	user 0.130s	sys 0.054s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774800,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":288,"lbm_read_time_us":14051,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31483,"lbm_writes_lt_1ms":543,"mutex_wait_us":62,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16640,"update_count":2500}
I20260812 06:20:12.994989 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=14.095187
I20260812 06:20:13.047860 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.053s	user 0.025s	sys 0.020s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20417,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:13.048384 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=2.188937
I20260812 06:20:13.064735 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6113,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:13.065361 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling MajorDeltaCompactionOp(1537d813c8b142d996c38f03ba2843c1): perf score=1.000000
I20260812 06:20:13.229821 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: MajorDeltaCompactionOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.164s	user 0.121s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":560,"lbm_read_time_us":11724,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33746,"lbm_writes_lt_1ms":543,"mutex_wait_us":294,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":2500}
I20260812 06:20:13.230726 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=11.118625
I20260812 06:20:13.265269 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.034s	user 0.015s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14353,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:13.265748 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=2.188937
I20260812 06:20:13.279491 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.014s	user 0.003s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4656,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:13.280025 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling MajorDeltaCompactionOp(1537d813c8b142d996c38f03ba2843c1): perf score=1.000000
I20260812 06:20:13.406126 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: MajorDeltaCompactionOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.126s	user 0.093s	sys 0.030s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":698,"lbm_read_time_us":8165,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24713,"lbm_writes_lt_1ms":443,"mutex_wait_us":46,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2000}
I20260812 06:20:13.406821 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=11.118625
I20260812 06:20:13.441561 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.035s	user 0.019s	sys 0.013s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15238,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:13.442147 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=2.188937
I20260812 06:20:13.456172 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5167,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:13.456782 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling MajorDeltaCompactionOp(1537d813c8b142d996c38f03ba2843c1): perf score=1.000000
I20260812 06:20:13.594211 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: MajorDeltaCompactionOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.137s	user 0.097s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":351,"lbm_read_time_us":11362,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26572,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4736,"update_count":2000}
I20260812 06:20:13.594974 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=10.126437
I20260812 06:20:13.649765 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.055s	user 0.018s	sys 0.028s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16795,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:13.650377 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=2.188937
I20260812 06:20:13.661469 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4416,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:13.662026 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushMRSOp(1537d813c8b142d996c38f03ba2843c1): perf score=1.000000
I20260812 06:20:13.710264 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushMRSOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.048s	user 0.031s	sys 0.003s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":93,"dirs.run_cpu_time_us":236,"dirs.run_wall_time_us":1307,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1630,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:13.710978 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling LogGCOp(1537d813c8b142d996c38f03ba2843c1): free 124710243 bytes of WAL
I20260812 06:20:13.711244 23644 log_reader.cc:385] T 1537d813c8b142d996c38f03ba2843c1: removed 12 log segments from log reader
I20260812 06:20:13.711292 23644 log.cc:1079] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/1537d813c8b142d996c38f03ba2843c1/wal-000000003 (ops 12-16)
I20260812 06:20:13.711347 23644 log.cc:1079] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/1537d813c8b142d996c38f03ba2843c1/wal-000000004 (ops 17-21)
I20260812 06:20:13.711409 23644 log.cc:1079] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/1537d813c8b142d996c38f03ba2843c1/wal-000000005 (ops 22-26)
I20260812 06:20:13.711449 23644 log.cc:1079] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/1537d813c8b142d996c38f03ba2843c1/wal-000000006 (ops 27-31)
I20260812 06:20:13.711479 23644 log.cc:1079] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/1537d813c8b142d996c38f03ba2843c1/wal-000000007 (ops 32-36)
I20260812 06:20:13.711508 23644 log.cc:1079] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/1537d813c8b142d996c38f03ba2843c1/wal-000000008 (ops 37-41)
I20260812 06:20:13.711546 23644 log.cc:1079] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/1537d813c8b142d996c38f03ba2843c1/wal-000000009 (ops 42-46)
I20260812 06:20:13.711583 23644 log.cc:1079] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/1537d813c8b142d996c38f03ba2843c1/wal-000000010 (ops 47-51)
I20260812 06:20:13.711620 23644 log.cc:1079] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/1537d813c8b142d996c38f03ba2843c1/wal-000000011 (ops 52-56)
I20260812 06:20:13.711658 23644 log.cc:1079] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/1537d813c8b142d996c38f03ba2843c1/wal-000000012 (ops 57-61)
I20260812 06:20:13.711694 23644 log.cc:1079] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/1537d813c8b142d996c38f03ba2843c1/wal-000000013 (ops 62-66)
I20260812 06:20:13.711745 23644 log.cc:1079] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/1537d813c8b142d996c38f03ba2843c1/wal-000000014 (ops 67-71)
I20260812 06:20:13.742379 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: LogGCOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.031s	user 0.003s	sys 0.024s Metrics: {}
I20260812 06:20:13.742872 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling UndoDeltaBlockGCOp(1537d813c8b142d996c38f03ba2843c1): 472 bytes on disk
I20260812 06:20:13.743366 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: UndoDeltaBlockGCOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:20:13.743899 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=3.181125
I20260812 06:20:13.765995 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.022s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4512901,"delete_count":0,"lbm_write_time_us":7356,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:13.766448 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=2.188937
I20260812 06:20:13.776566 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3884,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:13.777089 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling MajorDeltaCompactionOp(1537d813c8b142d996c38f03ba2843c1): perf score=1.000000
I20260812 06:20:13.996224 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: MajorDeltaCompactionOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.219s	user 0.139s	sys 0.080s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":555,"lbm_read_time_us":15978,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36709,"lbm_writes_lt_1ms":643,"mutex_wait_us":124,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10368,"thread_start_us":85,"threads_started":1,"update_count":3000}
I20260812 06:20:13.998266 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=14.095187
I20260812 06:20:14.048790 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.050s	user 0.032s	sys 0.013s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21433,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:14.049362 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=2.188937
I20260812 06:20:14.062387 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5060,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.063088 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling MajorDeltaCompactionOp(1537d813c8b142d996c38f03ba2843c1): perf score=1.000000
I20260812 06:20:14.257030 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: MajorDeltaCompactionOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.194s	user 0.130s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":180,"lbm_read_time_us":14136,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32940,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":2500}
I20260812 06:20:14.257718 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=14.095187
I20260812 06:20:14.334564 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.077s	user 0.037s	sys 0.023s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20693,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2000}
I20260812 06:20:14.335183 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=2.188937
I20260812 06:20:14.352425 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.017s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6505,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.353026 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling MajorDeltaCompactionOp(1537d813c8b142d996c38f03ba2843c1): perf score=1.000000
I20260812 06:20:14.544188 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: MajorDeltaCompactionOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.191s	user 0.138s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":222,"lbm_read_time_us":14091,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30750,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8576,"update_count":2500}
I20260812 06:20:14.544871 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=11.118625
I20260812 06:20:14.598317 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.053s	user 0.014s	sys 0.023s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":13162,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:14.599341 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=3.181125
I20260812 06:20:14.613970 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.014s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4348806,"delete_count":0,"lbm_write_time_us":5303,"lbm_writes_lt_1ms":109,"reinsert_count":0,"update_count":530}
I20260812 06:20:14.614600 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=2.188937
I20260812 06:20:14.627235 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3446255,"delete_count":0,"lbm_write_time_us":4761,"lbm_writes_lt_1ms":87,"reinsert_count":0,"update_count":420}
I20260812 06:20:14.627821 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling MajorDeltaCompactionOp(1537d813c8b142d996c38f03ba2843c1): perf score=1.000000
I20260812 06:20:14.804411 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: MajorDeltaCompactionOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.176s	user 0.120s	sys 0.056s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774797,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":751,"lbm_read_time_us":12298,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28712,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14720,"update_count":2500}
I20260812 06:20:14.804931 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=14.095187
I20260812 06:20:14.871052 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.066s	user 0.024s	sys 0.039s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22079,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:14.871675 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=2.188937
I20260812 06:20:14.882732 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4330,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:14.883176 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling MajorDeltaCompactionOp(1537d813c8b142d996c38f03ba2843c1): perf score=1.000000
I20260812 06:20:15.086683 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: MajorDeltaCompactionOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.203s	user 0.147s	sys 0.050s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":229,"lbm_read_time_us":13468,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32450,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17152,"update_count":2500}
I20260812 06:20:15.087484 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=14.095187
I20260812 06:20:15.139335 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.052s	user 0.022s	sys 0.021s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19741,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:15.139860 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=2.188937
I20260812 06:20:15.153143 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.013s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5872,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.153744 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling MajorDeltaCompactionOp(1537d813c8b142d996c38f03ba2843c1): perf score=1.000000
I20260812 06:20:15.342645 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: MajorDeltaCompactionOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.189s	user 0.134s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":842,"lbm_read_time_us":12436,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29303,"lbm_writes_lt_1ms":543,"mutex_wait_us":331,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13824,"update_count":2500}
I20260812 06:20:15.343238 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=14.095187
I20260812 06:20:15.396193 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.053s	user 0.035s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21310,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:15.396791 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=2.188937
I20260812 06:20:15.408572 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4241,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.409093 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushMRSOp(1537d813c8b142d996c38f03ba2843c1): perf score=1.000000
I20260812 06:20:15.437783 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushMRSOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.028s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":221,"dirs.run_wall_time_us":1476,"drs_written":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1795,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:15.438490 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling LogGCOp(1537d813c8b142d996c38f03ba2843c1): free 133024453 bytes of WAL
I20260812 06:20:15.438786 23644 log_reader.cc:385] T 1537d813c8b142d996c38f03ba2843c1: removed 13 log segments from log reader
I20260812 06:20:15.438848 23644 log.cc:1079] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/1537d813c8b142d996c38f03ba2843c1/wal-000000015 (ops 72-76)
I20260812 06:20:15.438887 23644 log.cc:1079] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/1537d813c8b142d996c38f03ba2843c1/wal-000000016 (ops 77-81)
I20260812 06:20:15.438918 23644 log.cc:1079] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/1537d813c8b142d996c38f03ba2843c1/wal-000000017 (ops 82-86)
I20260812 06:20:15.438953 23644 log.cc:1079] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/1537d813c8b142d996c38f03ba2843c1/wal-000000018 (ops 87-90)
I20260812 06:20:15.438977 23644 log.cc:1079] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/1537d813c8b142d996c38f03ba2843c1/wal-000000019 (ops 91-95)
I20260812 06:20:15.439002 23644 log.cc:1079] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/1537d813c8b142d996c38f03ba2843c1/wal-000000020 (ops 96-100)
I20260812 06:20:15.439028 23644 log.cc:1079] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/1537d813c8b142d996c38f03ba2843c1/wal-000000021 (ops 101-105)
I20260812 06:20:15.439056 23644 log.cc:1079] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/1537d813c8b142d996c38f03ba2843c1/wal-000000022 (ops 106-110)
I20260812 06:20:15.439085 23644 log.cc:1079] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/1537d813c8b142d996c38f03ba2843c1/wal-000000023 (ops 111-115)
I20260812 06:20:15.439119 23644 log.cc:1079] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/1537d813c8b142d996c38f03ba2843c1/wal-000000024 (ops 116-120)
I20260812 06:20:15.439150 23644 log.cc:1079] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/1537d813c8b142d996c38f03ba2843c1/wal-000000025 (ops 121-125)
I20260812 06:20:15.439175 23644 log.cc:1079] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/1537d813c8b142d996c38f03ba2843c1/wal-000000026 (ops 126-130)
I20260812 06:20:15.439201 23644 log.cc:1079] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/1537d813c8b142d996c38f03ba2843c1/wal-000000027 (ops 131-135)
I20260812 06:20:15.474494 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: LogGCOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.036s	user 0.004s	sys 0.028s Metrics: {}
I20260812 06:20:15.482308 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling UndoDeltaBlockGCOp(1537d813c8b142d996c38f03ba2843c1): 493 bytes on disk
I20260812 06:20:15.482959 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: UndoDeltaBlockGCOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4}
I20260812 06:20:15.483675 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=2.188937
I20260812 06:20:15.506485 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.023s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6690,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.506986 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=2.188937
I20260812 06:20:15.518332 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.011s	user 0.008s	sys 0.002s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4498,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.518872 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling MajorDeltaCompactionOp(1537d813c8b142d996c38f03ba2843c1): perf score=1.000000
I20260812 06:20:15.781757 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: MajorDeltaCompactionOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.263s	user 0.142s	sys 0.117s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979749,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":778,"lbm_read_time_us":17238,"lbm_reads_lt_1ms":774,"lbm_write_time_us":43562,"lbm_writes_lt_1ms":743,"mutex_wait_us":363,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":6144,"thread_start_us":96,"threads_started":1,"update_count":3500}
I20260812 06:20:15.782903 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=18.063937
I20260812 06:20:15.861306 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.078s	user 0.042s	sys 0.020s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":30257,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:15.861934 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=2.188937
I20260812 06:20:15.875686 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5243,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:15.876245 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling MajorDeltaCompactionOp(1537d813c8b142d996c38f03ba2843c1): perf score=1.000000
I20260812 06:20:16.107380 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: MajorDeltaCompactionOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.231s	user 0.142s	sys 0.078s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877101,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":297,"lbm_read_time_us":17473,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33666,"lbm_writes_lt_1ms":643,"mutex_wait_us":91,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9728,"update_count":3000}
I20260812 06:20:16.108099 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=18.063937
I20260812 06:20:16.182327 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.074s	user 0.036s	sys 0.033s Metrics: {"bytes_written":20512322,"delete_count":0,"lbm_write_time_us":35556,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:16.182895 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=2.188937
I20260812 06:20:16.199769 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.017s	user 0.010s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6673,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.200436 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling MajorDeltaCompactionOp(1537d813c8b142d996c38f03ba2843c1): perf score=1.000000
I20260812 06:20:16.404479 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: MajorDeltaCompactionOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.204s	user 0.127s	sys 0.077s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877109,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":232,"lbm_read_time_us":14879,"lbm_reads_lt_1ms":664,"lbm_write_time_us":33369,"lbm_writes_lt_1ms":643,"mutex_wait_us":49,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":17536,"update_count":3000}
I20260812 06:20:16.405339 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=14.095187
I20260812 06:20:16.457465 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.052s	user 0.037s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23940,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:16.458052 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=2.188937
I20260812 06:20:16.472659 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5454,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.473201 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling MajorDeltaCompactionOp(1537d813c8b142d996c38f03ba2843c1): perf score=1.000000
I20260812 06:20:16.655313 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: MajorDeltaCompactionOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.182s	user 0.141s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":437,"lbm_read_time_us":14534,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30343,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4736,"update_count":2500}
I20260812 06:20:16.656093 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=14.095187
I20260812 06:20:16.717825 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.062s	user 0.028s	sys 0.023s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19832,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:16.718437 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=2.188937
I20260812 06:20:16.729516 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4170,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:16.730082 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling MajorDeltaCompactionOp(1537d813c8b142d996c38f03ba2843c1): perf score=1.000000
I20260812 06:20:16.916851 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: MajorDeltaCompactionOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.187s	user 0.123s	sys 0.058s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":157,"lbm_read_time_us":13423,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30041,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":22016,"update_count":2500}
I20260812 06:20:16.917657 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=11.118625
I20260812 06:20:16.955161 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.037s	user 0.029s	sys 0.008s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":15586,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:16.955892 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=2.188937
I20260812 06:20:16.978762 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.023s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4755,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:16.979236 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushMRSOp(1537d813c8b142d996c38f03ba2843c1): perf score=1.000000
I20260812 06:20:17.022190 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushMRSOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.043s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":212,"dirs.run_wall_time_us":1971,"drs_written":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1760,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:17.023046 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=3.181125
I20260812 06:20:17.039727 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.016s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4815,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:17.040331 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling LogGCOp(1537d813c8b142d996c38f03ba2843c1): free 112239552 bytes of WAL
I20260812 06:20:17.040601 23644 log_reader.cc:385] T 1537d813c8b142d996c38f03ba2843c1: removed 11 log segments from log reader
I20260812 06:20:17.040670 23644 log.cc:1079] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/1537d813c8b142d996c38f03ba2843c1/wal-000000028 (ops 136-140)
I20260812 06:20:17.040721 23644 log.cc:1079] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/1537d813c8b142d996c38f03ba2843c1/wal-000000029 (ops 141-145)
I20260812 06:20:17.040781 23644 log.cc:1079] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/1537d813c8b142d996c38f03ba2843c1/wal-000000030 (ops 146-150)
I20260812 06:20:17.040827 23644 log.cc:1079] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/1537d813c8b142d996c38f03ba2843c1/wal-000000031 (ops 151-154)
I20260812 06:20:17.040863 23644 log.cc:1079] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/1537d813c8b142d996c38f03ba2843c1/wal-000000032 (ops 155-159)
I20260812 06:20:17.040902 23644 log.cc:1079] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/1537d813c8b142d996c38f03ba2843c1/wal-000000033 (ops 160-164)
I20260812 06:20:17.040942 23644 log.cc:1079] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/1537d813c8b142d996c38f03ba2843c1/wal-000000034 (ops 165-169)
I20260812 06:20:17.040982 23644 log.cc:1079] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/1537d813c8b142d996c38f03ba2843c1/wal-000000035 (ops 170-174)
I20260812 06:20:17.041023 23644 log.cc:1079] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/1537d813c8b142d996c38f03ba2843c1/wal-000000036 (ops 175-179)
I20260812 06:20:17.041062 23644 log.cc:1079] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/1537d813c8b142d996c38f03ba2843c1/wal-000000037 (ops 180-184)
I20260812 06:20:17.041102 23644 log.cc:1079] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/1537d813c8b142d996c38f03ba2843c1/wal-000000038 (ops 185-189)
I20260812 06:20:17.067548 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: LogGCOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:20:17.068033 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling UndoDeltaBlockGCOp(1537d813c8b142d996c38f03ba2843c1): 462 bytes on disk
I20260812 06:20:17.068691 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: UndoDeltaBlockGCOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:20:17.069269 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=2.188937
I20260812 06:20:17.087222 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.018s	user 0.013s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6008,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.087709 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling LogGCOp(1537d813c8b142d996c38f03ba2843c1): free 12017954 bytes of WAL
I20260812 06:20:17.087977 23644 log_reader.cc:385] T 1537d813c8b142d996c38f03ba2843c1: removed 1 log segments from log reader
I20260812 06:20:17.088035 23644 log.cc:1079] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: Deleting log segment in path: /tmp/dist-test-taskzTOAgm/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515606047264-23333-0/minicluster-data/ts-0-root/wals/1537d813c8b142d996c38f03ba2843c1/wal-000000039 (ops 190-194)
I20260812 06:20:17.091502 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: LogGCOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.004s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:20:17.091852 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=2.188937
I20260812 06:20:17.102449 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3958,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:17.103103 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling MajorDeltaCompactionOp(1537d813c8b142d996c38f03ba2843c1): perf score=1.000000
I20260812 06:20:17.240511 23333 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.237s	user 1.832s	sys 0.215s
I20260812 06:20:17.333940 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: MajorDeltaCompactionOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.230s	user 0.120s	sys 0.107s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979849,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":3493,"lbm_read_time_us":17273,"lbm_reads_lt_1ms":771,"lbm_write_time_us":35510,"lbm_writes_lt_1ms":743,"mutex_wait_us":2749,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":65280,"thread_start_us":102,"threads_started":1,"update_count":3500}
I20260812 06:20:17.334782 23709 maintenance_manager.cc:419] P bee236fb7a71469a9d1086c6a09e6d25: Scheduling FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1): perf score=10.126437
I20260812 06:20:17.345034 23333 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.104s	user 0.002s	sys 0.000s
I20260812 06:20:17.345646 23333 tablet_server.cc:179] TabletServer@127.22.201.65:0 shutting down...
I20260812 06:20:17.370182 23644 maintenance_manager.cc:643] P bee236fb7a71469a9d1086c6a09e6d25: FlushDeltaMemStoresOp(1537d813c8b142d996c38f03ba2843c1) complete. Timing: real 0.035s	user 0.022s	sys 0.009s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15742,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:17.370800 23333 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:17.371037 23333 tablet_replica.cc:333] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25: stopping tablet replica
I20260812 06:20:17.371177 23333 raft_consensus.cc:2243] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:17.371332 23333 raft_consensus.cc:2272] T 1537d813c8b142d996c38f03ba2843c1 P bee236fb7a71469a9d1086c6a09e6d25 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:17.375075 23333 tablet_server.cc:196] TabletServer@127.22.201.65:0 shutdown complete.
I20260812 06:20:17.388912 23333 master.cc:562] Master@127.22.201.126:42787 shutting down...
I20260812 06:20:17.392500 23333 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 1d835205c7cb4abaac13740dd07eec8d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:17.392691 23333 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 1d835205c7cb4abaac13740dd07eec8d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:17.392745 23333 tablet_replica.cc:333] T 00000000000000000000000000000000 P 1d835205c7cb4abaac13740dd07eec8d: stopping tablet replica
I20260812 06:20:17.405151 23333 master.cc:584] Master@127.22.201.126:42787 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5722 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11440 ms total)

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