[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:17:27.164583 27122 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.26.124.190:45911
I20260812 06:17:27.165721 27122 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:17:27.166399 27122 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:27.173795 27138 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:27.173799 27131 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:27.173851 27122 server_base.cc:1061] running on GCE node
W20260812 06:17:27.174081 27132 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:27.174670 27122 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:27.174813 27122 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:27.174871 27122 hybrid_clock.cc:648] HybridClock initialized: now 1786515447174868 us; error 0 us; skew 500 ppm
I20260812 06:17:27.176766 27122 webserver.cc:533] Webserver started at http://127.26.124.190:46379/ using document root <none> and password file <none>
I20260812 06:17:27.177362 27122 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:27.177454 27122 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:27.177750 27122 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:27.179471 27122 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/master-0-root/instance:
uuid: "4ab84a4429ff47aa966462a4704b139f"
format_stamp: "Formatted at 2026-08-12 06:17:27 on dist-test-slave-gkw7"
I20260812 06:17:27.183272 27122 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:17:27.185480 27145 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:27.186582 27122 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:27.186723 27122 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/master-0-root
uuid: "4ab84a4429ff47aa966462a4704b139f"
format_stamp: "Formatted at 2026-08-12 06:17:27 on dist-test-slave-gkw7"
I20260812 06:17:27.186844 27122 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:27.205185 27122 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:27.205927 27122 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:17:27.206123 27122 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:27.214538 27122 rpc_server.cc:307] RPC server started. Bound to: 127.26.124.190:45911
I20260812 06:17:27.214560 27229 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.124.190:45911 every 8 connection(s)
I20260812 06:17:27.216894 27233 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:27.222404 27233 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4ab84a4429ff47aa966462a4704b139f: Bootstrap starting.
I20260812 06:17:27.224774 27233 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 4ab84a4429ff47aa966462a4704b139f: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:27.225793 27233 log.cc:826] T 00000000000000000000000000000000 P 4ab84a4429ff47aa966462a4704b139f: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:27.227545 27233 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4ab84a4429ff47aa966462a4704b139f: No bootstrap required, opened a new log
I20260812 06:17:27.230350 27233 raft_consensus.cc:359] T 00000000000000000000000000000000 P 4ab84a4429ff47aa966462a4704b139f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4ab84a4429ff47aa966462a4704b139f" member_type: VOTER }
I20260812 06:17:27.230515 27233 raft_consensus.cc:385] T 00000000000000000000000000000000 P 4ab84a4429ff47aa966462a4704b139f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:27.230610 27233 raft_consensus.cc:740] T 00000000000000000000000000000000 P 4ab84a4429ff47aa966462a4704b139f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 4ab84a4429ff47aa966462a4704b139f, State: Initialized, Role: FOLLOWER
I20260812 06:17:27.231264 27233 consensus_queue.cc:260] T 00000000000000000000000000000000 P 4ab84a4429ff47aa966462a4704b139f [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: "4ab84a4429ff47aa966462a4704b139f" member_type: VOTER }
I20260812 06:17:27.231451 27233 raft_consensus.cc:399] T 00000000000000000000000000000000 P 4ab84a4429ff47aa966462a4704b139f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:27.231524 27233 raft_consensus.cc:493] T 00000000000000000000000000000000 P 4ab84a4429ff47aa966462a4704b139f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:27.231709 27233 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 4ab84a4429ff47aa966462a4704b139f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:27.232537 27233 raft_consensus.cc:515] T 00000000000000000000000000000000 P 4ab84a4429ff47aa966462a4704b139f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4ab84a4429ff47aa966462a4704b139f" member_type: VOTER }
I20260812 06:17:27.232993 27233 leader_election.cc:304] T 00000000000000000000000000000000 P 4ab84a4429ff47aa966462a4704b139f [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: 4ab84a4429ff47aa966462a4704b139f; no voters: 
I20260812 06:17:27.233331 27233 leader_election.cc:290] T 00000000000000000000000000000000 P 4ab84a4429ff47aa966462a4704b139f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:27.233491 27236 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 4ab84a4429ff47aa966462a4704b139f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:27.233796 27236 raft_consensus.cc:697] T 00000000000000000000000000000000 P 4ab84a4429ff47aa966462a4704b139f [term 1 LEADER]: Becoming Leader. State: Replica: 4ab84a4429ff47aa966462a4704b139f, State: Running, Role: LEADER
I20260812 06:17:27.234227 27236 consensus_queue.cc:237] T 00000000000000000000000000000000 P 4ab84a4429ff47aa966462a4704b139f [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: "4ab84a4429ff47aa966462a4704b139f" member_type: VOTER }
I20260812 06:17:27.234464 27233 sys_catalog.cc:565] T 00000000000000000000000000000000 P 4ab84a4429ff47aa966462a4704b139f [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:27.236287 27238 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4ab84a4429ff47aa966462a4704b139f [sys.catalog]: SysCatalogTable state changed. Reason: New leader 4ab84a4429ff47aa966462a4704b139f. Latest consensus state: current_term: 1 leader_uuid: "4ab84a4429ff47aa966462a4704b139f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4ab84a4429ff47aa966462a4704b139f" member_type: VOTER } }
I20260812 06:17:27.236332 27237 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4ab84a4429ff47aa966462a4704b139f [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "4ab84a4429ff47aa966462a4704b139f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4ab84a4429ff47aa966462a4704b139f" member_type: VOTER } }
I20260812 06:17:27.236428 27237 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4ab84a4429ff47aa966462a4704b139f [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:27.236431 27238 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4ab84a4429ff47aa966462a4704b139f [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:27.236990 27122 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:17:27.238955 27257 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 4ab84a4429ff47aa966462a4704b139f: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:17:27.239020 27257 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:17:27.239106 27254 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:27.239867 27254 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:27.244521 27254 catalog_manager.cc:1383] Generated new cluster ID: 31f9c04dc3314182a49c6d745122850b
I20260812 06:17:27.244593 27254 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:27.250886 27254 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:27.251978 27254 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:27.268914 27254 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 4ab84a4429ff47aa966462a4704b139f: Generated new TSK 0
I20260812 06:17:27.269695 27254 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:27.302066 27122 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:27.305341 27261 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:27.305369 27263 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:27.305627 27265 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:27.305773 27122 server_base.cc:1061] running on GCE node
I20260812 06:17:27.305987 27122 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:27.306043 27122 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:27.306113 27122 hybrid_clock.cc:648] HybridClock initialized: now 1786515447306111 us; error 0 us; skew 500 ppm
I20260812 06:17:27.307138 27122 webserver.cc:533] Webserver started at http://127.26.124.129:40181/ using document root <none> and password file <none>
I20260812 06:17:27.307322 27122 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:27.307395 27122 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:27.307476 27122 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:27.307893 27122 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/instance:
uuid: "3bdfcc23e71640a2aaf544e34fab1c58"
format_stamp: "Formatted at 2026-08-12 06:17:27 on dist-test-slave-gkw7"
I20260812 06:17:27.309506 27122 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.001s
I20260812 06:17:27.310596 27276 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:27.310848 27122 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:27.310925 27122 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root
uuid: "3bdfcc23e71640a2aaf544e34fab1c58"
format_stamp: "Formatted at 2026-08-12 06:17:27 on dist-test-slave-gkw7"
I20260812 06:17:27.311017 27122 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:27.340711 27122 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:27.341244 27122 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:27.341868 27122 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:27.342836 27122 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:27.342890 27122 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:27.342932 27122 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:27.342993 27122 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:27.349963 27122 rpc_server.cc:307] RPC server started. Bound to: 127.26.124.129:37251
I20260812 06:17:27.350003 27372 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.124.129:37251 every 8 connection(s)
I20260812 06:17:27.360222 27373 heartbeater.cc:344] Connected to a master server at 127.26.124.190:45911
I20260812 06:17:27.360512 27373 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:27.361006 27373 heartbeater.cc:507] Master 127.26.124.190:45911 requested a full tablet report, sending...
I20260812 06:17:27.362682 27176 ts_manager.cc:194] Registered new tserver with Master: 3bdfcc23e71640a2aaf544e34fab1c58 (127.26.124.129:37251)
I20260812 06:17:27.363029 27122 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012378737s
I20260812 06:17:27.364235 27176 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:42140
I20260812 06:17:27.378170 27176 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:42148:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:27.395591 27322 tablet_service.cc:1511] Processing CreateTablet for tablet fdf89e715d764b26a118ac77d5818512 (DEFAULT_TABLE table=heavy-update-compaction-test [id=989da660c8a343e9b345c15f11ef7bc0]), partition=
I20260812 06:17:27.396144 27322 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet fdf89e715d764b26a118ac77d5818512. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:27.399379 27390 tablet_bootstrap.cc:492] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Bootstrap starting.
I20260812 06:17:27.400480 27390 tablet_bootstrap.cc:654] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:27.401827 27390 tablet_bootstrap.cc:492] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: No bootstrap required, opened a new log
I20260812 06:17:27.401984 27390 ts_tablet_manager.cc:1403] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:17:27.402673 27390 raft_consensus.cc:359] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3bdfcc23e71640a2aaf544e34fab1c58" member_type: VOTER last_known_addr { host: "127.26.124.129" port: 37251 } }
I20260812 06:17:27.402827 27390 raft_consensus.cc:385] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:27.402884 27390 raft_consensus.cc:740] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3bdfcc23e71640a2aaf544e34fab1c58, State: Initialized, Role: FOLLOWER
I20260812 06:17:27.403046 27390 consensus_queue.cc:260] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58 [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: "3bdfcc23e71640a2aaf544e34fab1c58" member_type: VOTER last_known_addr { host: "127.26.124.129" port: 37251 } }
I20260812 06:17:27.403129 27390 raft_consensus.cc:399] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:27.403193 27390 raft_consensus.cc:493] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:27.403257 27390 raft_consensus.cc:3060] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:27.404026 27390 raft_consensus.cc:515] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3bdfcc23e71640a2aaf544e34fab1c58" member_type: VOTER last_known_addr { host: "127.26.124.129" port: 37251 } }
I20260812 06:17:27.404191 27390 leader_election.cc:304] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58 [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: 3bdfcc23e71640a2aaf544e34fab1c58; no voters: 
I20260812 06:17:27.404479 27390 leader_election.cc:290] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:27.404603 27395 raft_consensus.cc:2804] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:27.404846 27395 raft_consensus.cc:697] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58 [term 1 LEADER]: Becoming Leader. State: Replica: 3bdfcc23e71640a2aaf544e34fab1c58, State: Running, Role: LEADER
I20260812 06:17:27.404909 27390 ts_tablet_manager.cc:1434] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:17:27.405115 27373 heartbeater.cc:499] Master 127.26.124.190:45911 was elected leader, sending a full tablet report...
I20260812 06:17:27.405393 27395 consensus_queue.cc:237] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58 [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: "3bdfcc23e71640a2aaf544e34fab1c58" member_type: VOTER last_known_addr { host: "127.26.124.129" port: 37251 } }
I20260812 06:17:27.408466 27176 catalog_manager.cc:5719] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58 reported cstate change: term changed from 0 to 1, leader changed from <none> to 3bdfcc23e71640a2aaf544e34fab1c58 (127.26.124.129). New cstate: current_term: 1 leader_uuid: "3bdfcc23e71640a2aaf544e34fab1c58" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3bdfcc23e71640a2aaf544e34fab1c58" member_type: VOTER last_known_addr { host: "127.26.124.129" port: 37251 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:27.474103 27122 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.058s	user 0.025s	sys 0.004s
I20260812 06:17:27.601133 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushMRSOp(fdf89e715d764b26a118ac77d5818512): perf score=15.086190
I20260812 06:17:27.742755 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushMRSOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.141s	user 0.108s	sys 0.031s Metrics: {"bytes_written":8820443,"cfile_init":1,"compiler_manager_pool.queue_time_us":253,"delete_count":0,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":204,"dirs.run_wall_time_us":739,"drs_written":1,"lbm_read_time_us":106,"lbm_reads_lt_1ms":4,"lbm_write_time_us":34064,"lbm_writes_lt_1ms":582,"mutex_wait_us":196,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":163584,"thread_start_us":114,"threads_started":1,"update_count":1075}
I20260812 06:17:27.744339 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling LogGCOp(fdf89e715d764b26a118ac77d5818512): free 20743880 bytes of WAL
I20260812 06:17:27.744701 27282 log_reader.cc:385] T fdf89e715d764b26a118ac77d5818512: removed 2 log segments from log reader
I20260812 06:17:27.744774 27282 log.cc:1079] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/fdf89e715d764b26a118ac77d5818512/wal-000000001 (ops 1-6)
I20260812 06:17:27.744832 27282 log.cc:1079] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/fdf89e715d764b26a118ac77d5818512/wal-000000002 (ops 7-11)
I20260812 06:17:27.750851 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: LogGCOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.006s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:17:27.751319 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=1.196750
I20260812 06:17:27.764869 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.013s	user 0.005s	sys 0.006s Metrics: {"bytes_written":3077030,"delete_count":0,"lbm_write_time_us":4206,"lbm_writes_lt_1ms":78,"reinsert_count":0,"update_count":375}
I20260812 06:17:27.765363 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling UndoDeltaBlockGCOp(fdf89e715d764b26a118ac77d5818512): 12719218 bytes on disk
I20260812 06:17:27.765938 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: UndoDeltaBlockGCOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4}
I20260812 06:17:27.766350 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512): perf score=1.000000
I20260812 06:17:27.877823 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.111s	user 0.064s	sys 0.044s Metrics: {"cfile_cache_miss":322,"cfile_cache_miss_bytes":16159601,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":577,"lbm_read_time_us":6422,"lbm_reads_lt_1ms":350,"lbm_write_time_us":20648,"lbm_writes_lt_1ms":333,"mutex_wait_us":62,"peak_mem_usage":36812022,"reinsert_count":0,"spinlock_wait_cycles":8960,"thread_start_us":351,"threads_started":5,"update_count":1450}
I20260812 06:17:27.878535 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=7.149875
I20260812 06:17:27.902458 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.024s	user 0.012s	sys 0.011s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":10235,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:17:27.903021 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=2.188937
I20260812 06:17:27.917204 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.014s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5442,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:27.917762 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512): perf score=1.000000
I20260812 06:17:28.028523 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.111s	user 0.091s	sys 0.017s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16569856,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":170,"lbm_read_time_us":7414,"lbm_reads_lt_1ms":364,"lbm_write_time_us":19562,"lbm_writes_lt_1ms":343,"mutex_wait_us":41,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:17:28.029155 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=10.126437
I20260812 06:17:28.079809 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.050s	user 0.023s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17107,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:28.080353 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=2.188937
I20260812 06:17:28.091246 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4012,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:28.091773 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512): perf score=1.000000
I20260812 06:17:28.220623 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.129s	user 0.098s	sys 0.030s 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":899,"lbm_read_time_us":9914,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23732,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8192,"update_count":2000}
I20260812 06:17:28.221153 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=10.126437
I20260812 06:17:28.265179 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.044s	user 0.020s	sys 0.016s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17590,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:28.265712 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=2.188937
I20260812 06:17:28.277319 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.011s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4062,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:28.277810 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512): perf score=1.000000
I20260812 06:17:28.405916 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.128s	user 0.098s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":220,"lbm_read_time_us":9592,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26282,"lbm_writes_lt_1ms":443,"mutex_wait_us":79,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18176,"update_count":2000}
I20260812 06:17:28.406653 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=10.126437
I20260812 06:17:28.450300 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.043s	user 0.023s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19271,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:28.450760 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=2.188937
I20260812 06:17:28.467550 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.017s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6120,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:28.468063 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512): perf score=1.000000
I20260812 06:17:28.589835 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.122s	user 0.088s	sys 0.032s 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":404,"lbm_read_time_us":8052,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24767,"lbm_writes_lt_1ms":443,"mutex_wait_us":108,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":83840,"update_count":2000}
I20260812 06:17:28.590525 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=11.118625
I20260812 06:17:28.630674 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.040s	user 0.022s	sys 0.015s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13603,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:28.631400 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=2.188937
I20260812 06:17:28.646049 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.014s	user 0.010s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5648,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:28.646684 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512): perf score=1.000000
I20260812 06:17:28.805778 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.159s	user 0.102s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":591,"lbm_read_time_us":10244,"lbm_reads_lt_1ms":468,"lbm_write_time_us":26294,"lbm_writes_lt_1ms":443,"mutex_wait_us":370,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":2000}
I20260812 06:17:28.806375 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=11.118625
I20260812 06:17:28.840871 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.034s	user 0.014s	sys 0.017s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":14860,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:28.841424 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=2.188937
I20260812 06:17:28.859010 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.017s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5818,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:28.859489 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512): perf score=1.000000
I20260812 06:17:28.983680 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.124s	user 0.088s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1184,"lbm_read_time_us":10082,"lbm_reads_lt_1ms":468,"lbm_write_time_us":24344,"lbm_writes_lt_1ms":443,"mutex_wait_us":400,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2000}
I20260812 06:17:28.984428 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=10.126437
I20260812 06:17:29.024302 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.040s	user 0.016s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15317,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:29.025014 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=2.188937
I20260812 06:17:29.040891 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6036,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.041393 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushMRSOp(fdf89e715d764b26a118ac77d5818512): perf score=1.000000
I20260812 06:17:29.072763 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushMRSOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.031s	user 0.023s	sys 0.005s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":242,"dirs.run_wall_time_us":1250,"drs_written":1,"lbm_read_time_us":102,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2113,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:29.073890 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling LogGCOp(fdf89e715d764b26a118ac77d5818512): free 120553332 bytes of WAL
I20260812 06:17:29.074335 27282 log_reader.cc:385] T fdf89e715d764b26a118ac77d5818512: removed 12 log segments from log reader
I20260812 06:17:29.074396 27282 log.cc:1079] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/fdf89e715d764b26a118ac77d5818512/wal-000000003 (ops 12-16)
I20260812 06:17:29.074433 27282 log.cc:1079] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/fdf89e715d764b26a118ac77d5818512/wal-000000004 (ops 17-21)
I20260812 06:17:29.074458 27282 log.cc:1079] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/fdf89e715d764b26a118ac77d5818512/wal-000000005 (ops 22-26)
I20260812 06:17:29.074482 27282 log.cc:1079] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/fdf89e715d764b26a118ac77d5818512/wal-000000006 (ops 27-30)
I20260812 06:17:29.074507 27282 log.cc:1079] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/fdf89e715d764b26a118ac77d5818512/wal-000000007 (ops 31-35)
I20260812 06:17:29.074532 27282 log.cc:1079] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/fdf89e715d764b26a118ac77d5818512/wal-000000008 (ops 36-40)
I20260812 06:17:29.074553 27282 log.cc:1079] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/fdf89e715d764b26a118ac77d5818512/wal-000000009 (ops 41-45)
I20260812 06:17:29.074589 27282 log.cc:1079] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/fdf89e715d764b26a118ac77d5818512/wal-000000010 (ops 46-50)
I20260812 06:17:29.074610 27282 log.cc:1079] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/fdf89e715d764b26a118ac77d5818512/wal-000000011 (ops 51-55)
I20260812 06:17:29.074643 27282 log.cc:1079] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/fdf89e715d764b26a118ac77d5818512/wal-000000012 (ops 56-60)
I20260812 06:17:29.074669 27282 log.cc:1079] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/fdf89e715d764b26a118ac77d5818512/wal-000000013 (ops 61-64)
I20260812 06:17:29.074694 27282 log.cc:1079] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/fdf89e715d764b26a118ac77d5818512/wal-000000014 (ops 65-69)
I20260812 06:17:29.107043 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: LogGCOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.033s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:17:29.107467 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=2.188937
I20260812 06:17:29.127588 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.020s	user 0.005s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5676,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.128096 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling UndoDeltaBlockGCOp(fdf89e715d764b26a118ac77d5818512): 462 bytes on disk
I20260812 06:17:29.128557 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: UndoDeltaBlockGCOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4}
I20260812 06:17:29.129050 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=2.188937
I20260812 06:17:29.142865 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4674,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.143581 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512): perf score=1.000000
I20260812 06:17:29.340674 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.197s	user 0.127s	sys 0.069s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877338,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":739,"lbm_read_time_us":13134,"lbm_reads_lt_1ms":674,"lbm_write_time_us":40440,"lbm_writes_lt_1ms":643,"mutex_wait_us":53,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":85,"threads_started":1,"update_count":3000}
I20260812 06:17:29.341349 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=14.095187
I20260812 06:17:29.385977 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.044s	user 0.021s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19662,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:29.386505 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=2.188937
I20260812 06:17:29.399422 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4817,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.399855 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512): perf score=1.000000
I20260812 06:17:29.558667 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.159s	user 0.117s	sys 0.033s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":838,"lbm_read_time_us":11830,"lbm_reads_lt_1ms":568,"lbm_write_time_us":29384,"lbm_writes_lt_1ms":543,"mutex_wait_us":299,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14976,"update_count":2500}
I20260812 06:17:29.559248 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=14.095187
I20260812 06:17:29.609715 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.050s	user 0.032s	sys 0.011s Metrics: {"bytes_written":16409907,"delete_count":0,"lbm_write_time_us":19195,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:29.610267 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=2.188937
I20260812 06:17:29.623872 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4607,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.624342 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512): perf score=1.000000
I20260812 06:17:29.777704 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.153s	user 0.121s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774694,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":182,"lbm_read_time_us":11424,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31263,"lbm_writes_lt_1ms":543,"mutex_wait_us":67,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:29.778323 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=14.095187
I20260812 06:17:29.828289 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.050s	user 0.034s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21471,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:29.828976 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=2.188937
I20260812 06:17:29.848254 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.019s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7536,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:29.848816 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512): perf score=1.000000
I20260812 06:17:30.035094 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.186s	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":186,"lbm_read_time_us":12006,"lbm_reads_lt_1ms":572,"lbm_write_time_us":38528,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":2500}
I20260812 06:17:30.035777 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=14.095187
I20260812 06:17:30.093134 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.057s	user 0.033s	sys 0.020s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":25426,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:30.093766 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=2.188937
I20260812 06:17:30.107810 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.014s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4562,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.108402 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512): perf score=1.000000
I20260812 06:17:30.293155 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.185s	user 0.129s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774693,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":330,"lbm_read_time_us":13392,"lbm_reads_lt_1ms":568,"lbm_write_time_us":31298,"lbm_writes_lt_1ms":543,"mutex_wait_us":33,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":29696,"update_count":2500}
I20260812 06:17:30.293918 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=14.095187
I20260812 06:17:30.348708 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.055s	user 0.026s	sys 0.017s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20751,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:30.349254 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=2.188937
I20260812 06:17:30.360008 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4077,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.360512 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512): perf score=1.000000
I20260812 06:17:30.534297 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.174s	user 0.137s	sys 0.035s 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":495,"lbm_read_time_us":15800,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28399,"lbm_writes_lt_1ms":543,"mutex_wait_us":342,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2500}
I20260812 06:17:30.535022 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=11.118625
I20260812 06:17:30.584477 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.049s	user 0.023s	sys 0.023s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":16666,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:30.585175 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=2.188937
I20260812 06:17:30.596694 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4288,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:30.597718 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushMRSOp(fdf89e715d764b26a118ac77d5818512): perf score=1.000000
I20260812 06:17:30.637128 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushMRSOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.039s	user 0.028s	sys 0.006s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":96,"dirs.run_cpu_time_us":260,"dirs.run_wall_time_us":1313,"drs_written":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2378,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:30.638034 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling LogGCOp(fdf89e715d764b26a118ac77d5818512): free 124710301 bytes of WAL
I20260812 06:17:30.638288 27282 log_reader.cc:385] T fdf89e715d764b26a118ac77d5818512: removed 12 log segments from log reader
I20260812 06:17:30.638338 27282 log.cc:1079] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/fdf89e715d764b26a118ac77d5818512/wal-000000015 (ops 70-74)
I20260812 06:17:30.638368 27282 log.cc:1079] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/fdf89e715d764b26a118ac77d5818512/wal-000000016 (ops 75-79)
I20260812 06:17:30.638433 27282 log.cc:1079] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/fdf89e715d764b26a118ac77d5818512/wal-000000017 (ops 80-84)
I20260812 06:17:30.638478 27282 log.cc:1079] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/fdf89e715d764b26a118ac77d5818512/wal-000000018 (ops 85-89)
I20260812 06:17:30.638525 27282 log.cc:1079] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/fdf89e715d764b26a118ac77d5818512/wal-000000019 (ops 90-94)
I20260812 06:17:30.638582 27282 log.cc:1079] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/fdf89e715d764b26a118ac77d5818512/wal-000000020 (ops 95-99)
I20260812 06:17:30.638624 27282 log.cc:1079] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/fdf89e715d764b26a118ac77d5818512/wal-000000021 (ops 100-104)
I20260812 06:17:30.638664 27282 log.cc:1079] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/fdf89e715d764b26a118ac77d5818512/wal-000000022 (ops 105-109)
I20260812 06:17:30.638703 27282 log.cc:1079] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/fdf89e715d764b26a118ac77d5818512/wal-000000023 (ops 110-114)
I20260812 06:17:30.638743 27282 log.cc:1079] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/fdf89e715d764b26a118ac77d5818512/wal-000000024 (ops 115-119)
I20260812 06:17:30.638783 27282 log.cc:1079] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/fdf89e715d764b26a118ac77d5818512/wal-000000025 (ops 120-124)
I20260812 06:17:30.638828 27282 log.cc:1079] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/fdf89e715d764b26a118ac77d5818512/wal-000000026 (ops 125-129)
I20260812 06:17:30.667846 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: LogGCOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.030s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:17:30.668294 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=3.181125
I20260812 06:17:30.681838 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.013s	user 0.004s	sys 0.007s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4440,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:30.682298 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling UndoDeltaBlockGCOp(fdf89e715d764b26a118ac77d5818512): 483 bytes on disk
I20260812 06:17:30.682715 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: UndoDeltaBlockGCOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:17:30.683213 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=2.188937
I20260812 06:17:30.694032 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3974,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:30.694571 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512): perf score=1.000000
I20260812 06:17:30.906569 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.212s	user 0.144s	sys 0.067s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877321,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":532,"lbm_read_time_us":15574,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35852,"lbm_writes_lt_1ms":643,"mutex_wait_us":22,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":34432,"thread_start_us":82,"threads_started":1,"update_count":3000}
I20260812 06:17:30.907388 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=14.095187
I20260812 06:17:30.971239 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.064s	user 0.023s	sys 0.036s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":28182,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:30.971724 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=2.188937
I20260812 06:17:30.983204 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4167,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:30.983748 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512): perf score=1.000000
I20260812 06:17:31.160223 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.176s	user 0.125s	sys 0.047s 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":252,"lbm_read_time_us":11426,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30052,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4736,"update_count":2500}
I20260812 06:17:31.160926 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=14.095187
I20260812 06:17:31.221227 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.060s	user 0.034s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21708,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:31.221902 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=2.188937
I20260812 06:17:31.239203 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.017s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6505,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.239832 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512): perf score=1.000000
I20260812 06:17:31.412751 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.173s	user 0.132s	sys 0.040s 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":13992,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28134,"lbm_writes_lt_1ms":543,"mutex_wait_us":39,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20864,"update_count":2500}
I20260812 06:17:31.413640 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=10.126437
I20260812 06:17:31.448818 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.035s	user 0.022s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15330,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:31.449422 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=2.188937
I20260812 06:17:31.464653 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5671,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.465502 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512): perf score=1.000000
I20260812 06:17:31.622491 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.157s	user 0.115s	sys 0.036s 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":171,"lbm_read_time_us":12598,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22487,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12800,"update_count":2000}
I20260812 06:17:31.623268 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=10.126437
I20260812 06:17:31.657385 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.034s	user 0.020s	sys 0.012s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":14948,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:31.657958 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=2.188937
I20260812 06:17:31.668519 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4071,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.669092 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512): perf score=1.000000
I20260812 06:17:31.797219 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.128s	user 0.091s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":453,"lbm_read_time_us":9627,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24930,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":2000}
I20260812 06:17:31.797824 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=10.126437
I20260812 06:17:31.843508 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.045s	user 0.030s	sys 0.008s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17622,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:31.844055 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=2.188937
I20260812 06:17:31.855275 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.011s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4010,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:31.855790 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512): perf score=1.000000
I20260812 06:17:31.992462 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.136s	user 0.103s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1123,"lbm_read_time_us":9307,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25692,"lbm_writes_lt_1ms":443,"mutex_wait_us":495,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2000}
I20260812 06:17:31.993248 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=10.126437
I20260812 06:17:32.051797 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.058s	user 0.033s	sys 0.011s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17078,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:32.052326 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=2.188937
I20260812 06:17:32.062973 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4164,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.063457 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushMRSOp(fdf89e715d764b26a118ac77d5818512): perf score=1.000000
I20260812 06:17:32.097985 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushMRSOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.034s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":51,"dirs.run_cpu_time_us":214,"dirs.run_wall_time_us":1276,"drs_written":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1551,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:32.098685 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling LogGCOp(fdf89e715d764b26a118ac77d5818512): free 120553690 bytes of WAL
I20260812 06:17:32.098922 27282 log_reader.cc:385] T fdf89e715d764b26a118ac77d5818512: removed 12 log segments from log reader
I20260812 06:17:32.098996 27282 log.cc:1079] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/fdf89e715d764b26a118ac77d5818512/wal-000000027 (ops 130-134)
I20260812 06:17:32.099081 27282 log.cc:1079] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/fdf89e715d764b26a118ac77d5818512/wal-000000028 (ops 135-138)
I20260812 06:17:32.099120 27282 log.cc:1079] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/fdf89e715d764b26a118ac77d5818512/wal-000000029 (ops 139-143)
I20260812 06:17:32.099189 27282 log.cc:1079] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/fdf89e715d764b26a118ac77d5818512/wal-000000030 (ops 144-148)
I20260812 06:17:32.099231 27282 log.cc:1079] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/fdf89e715d764b26a118ac77d5818512/wal-000000031 (ops 149-152)
I20260812 06:17:32.099287 27282 log.cc:1079] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/fdf89e715d764b26a118ac77d5818512/wal-000000032 (ops 153-157)
I20260812 06:17:32.099326 27282 log.cc:1079] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/fdf89e715d764b26a118ac77d5818512/wal-000000033 (ops 158-162)
I20260812 06:17:32.099371 27282 log.cc:1079] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/fdf89e715d764b26a118ac77d5818512/wal-000000034 (ops 163-167)
I20260812 06:17:32.099414 27282 log.cc:1079] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/fdf89e715d764b26a118ac77d5818512/wal-000000035 (ops 168-172)
I20260812 06:17:32.099457 27282 log.cc:1079] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/fdf89e715d764b26a118ac77d5818512/wal-000000036 (ops 173-177)
I20260812 06:17:32.099499 27282 log.cc:1079] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/fdf89e715d764b26a118ac77d5818512/wal-000000037 (ops 178-182)
I20260812 06:17:32.099540 27282 log.cc:1079] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/fdf89e715d764b26a118ac77d5818512/wal-000000038 (ops 183-187)
I20260812 06:17:32.130885 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: LogGCOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.032s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:17:32.132290 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling UndoDeltaBlockGCOp(fdf89e715d764b26a118ac77d5818512): 447 bytes on disk
I20260812 06:17:32.132900 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: UndoDeltaBlockGCOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4}
I20260812 06:17:32.133581 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=2.188937
I20260812 06:17:32.152014 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.018s	user 0.015s	sys 0.000s Metrics: {"bytes_written":3856509,"delete_count":0,"lbm_write_time_us":6663,"lbm_writes_lt_1ms":97,"reinsert_count":0,"update_count":470}
I20260812 06:17:32.152693 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512): perf score=1.000000
I20260812 06:17:32.362046 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.208s	user 0.143s	sys 0.058s Metrics: {"cfile_cache_miss":527,"cfile_cache_miss_bytes":24528657,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1077,"lbm_read_time_us":18466,"lbm_reads_lt_1ms":563,"lbm_write_time_us":36405,"lbm_writes_lt_1ms":537,"peak_mem_usage":61829306,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":376,"threads_started":1,"update_count":2470}
I20260812 06:17:32.362627 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=15.087375
I20260812 06:17:32.437456 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.075s	user 0.040s	sys 0.021s Metrics: {"bytes_written":16656050,"delete_count":0,"lbm_write_time_us":23497,"lbm_writes_lt_1ms":409,"reinsert_count":0,"update_count":2030}
I20260812 06:17:32.438053 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=2.188937
I20260812 06:17:32.455310 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.017s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6530,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:32.455850 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512): perf score=1.000000
I20260812 06:17:32.559140 27122 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.085s	user 1.880s	sys 0.146s
I20260812 06:17:32.631333 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: MajorDeltaCompactionOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.175s	user 0.115s	sys 0.060s Metrics: {"cfile_cache_miss":538,"cfile_cache_miss_bytes":25020837,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":838,"lbm_read_time_us":16521,"lbm_reads_lt_1ms":574,"lbm_write_time_us":30665,"lbm_writes_lt_1ms":549,"mutex_wait_us":302,"peak_mem_usage":63362110,"reinsert_count":0,"update_count":2530}
I20260812 06:17:32.632102 27375 maintenance_manager.cc:419] P 3bdfcc23e71640a2aaf544e34fab1c58: Scheduling FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512): perf score=6.157687
I20260812 06:17:32.637331 27122 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.078s	user 0.003s	sys 0.000s
I20260812 06:17:32.638011 27122 tablet_server.cc:179] TabletServer@127.26.124.129:0 shutting down...
I20260812 06:17:32.656522 27282 maintenance_manager.cc:643] P 3bdfcc23e71640a2aaf544e34fab1c58: FlushDeltaMemStoresOp(fdf89e715d764b26a118ac77d5818512) complete. Timing: real 0.024s	user 0.011s	sys 0.011s Metrics: {"bytes_written":8205079,"delete_count":0,"lbm_write_time_us":10121,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:32.657186 27122 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:32.657631 27122 tablet_replica.cc:333] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58: stopping tablet replica
I20260812 06:17:32.657896 27122 raft_consensus.cc:2243] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:32.658161 27122 raft_consensus.cc:2272] T fdf89e715d764b26a118ac77d5818512 P 3bdfcc23e71640a2aaf544e34fab1c58 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:32.674960 27122 tablet_server.cc:196] TabletServer@127.26.124.129:0 shutdown complete.
I20260812 06:17:32.680711 27122 master.cc:562] Master@127.26.124.190:45911 shutting down...
I20260812 06:17:32.684839 27122 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 4ab84a4429ff47aa966462a4704b139f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:32.685052 27122 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 4ab84a4429ff47aa966462a4704b139f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:32.685142 27122 tablet_replica.cc:333] T 00000000000000000000000000000000 P 4ab84a4429ff47aa966462a4704b139f: stopping tablet replica
I20260812 06:17:32.698022 27122 master.cc:584] Master@127.26.124.190:45911 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5629 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:32.807325 27122 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.26.124.190:41323
I20260812 06:17:32.807811 27122 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:32.810369 27428 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:32.810375 27424 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:32.810585 27426 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:32.810648 27122 server_base.cc:1061] running on GCE node
I20260812 06:17:32.810885 27122 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:32.810925 27122 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:32.810940 27122 hybrid_clock.cc:648] HybridClock initialized: now 1786515452810940 us; error 0 us; skew 500 ppm
I20260812 06:17:32.811820 27122 webserver.cc:533] Webserver started at http://127.26.124.190:42281/ using document root <none> and password file <none>
I20260812 06:17:32.811959 27122 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:32.812006 27122 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:32.812062 27122 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:32.812458 27122 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/master-0-root/instance:
uuid: "88b411e5ceb2498b9ca8652941752145"
format_stamp: "Formatted at 2026-08-12 06:17:32 on dist-test-slave-gkw7"
I20260812 06:17:32.814138 27122 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:32.815086 27436 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:32.815402 27122 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:32.815471 27122 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/master-0-root
uuid: "88b411e5ceb2498b9ca8652941752145"
format_stamp: "Formatted at 2026-08-12 06:17:32 on dist-test-slave-gkw7"
I20260812 06:17:32.815567 27122 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:32.843119 27122 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:32.843648 27122 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:32.848137 27122 rpc_server.cc:307] RPC server started. Bound to: 127.26.124.190:41323
I20260812 06:17:32.851452 27514 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.124.190:41323 every 8 connection(s)
I20260812 06:17:32.853432 27517 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:32.855362 27517 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 88b411e5ceb2498b9ca8652941752145: Bootstrap starting.
I20260812 06:17:32.856164 27517 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 88b411e5ceb2498b9ca8652941752145: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:32.857254 27517 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 88b411e5ceb2498b9ca8652941752145: No bootstrap required, opened a new log
I20260812 06:17:32.857743 27517 raft_consensus.cc:359] T 00000000000000000000000000000000 P 88b411e5ceb2498b9ca8652941752145 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "88b411e5ceb2498b9ca8652941752145" member_type: VOTER }
I20260812 06:17:32.857831 27517 raft_consensus.cc:385] T 00000000000000000000000000000000 P 88b411e5ceb2498b9ca8652941752145 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:32.857853 27517 raft_consensus.cc:740] T 00000000000000000000000000000000 P 88b411e5ceb2498b9ca8652941752145 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 88b411e5ceb2498b9ca8652941752145, State: Initialized, Role: FOLLOWER
I20260812 06:17:32.858055 27517 consensus_queue.cc:260] T 00000000000000000000000000000000 P 88b411e5ceb2498b9ca8652941752145 [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: "88b411e5ceb2498b9ca8652941752145" member_type: VOTER }
I20260812 06:17:32.858139 27517 raft_consensus.cc:399] T 00000000000000000000000000000000 P 88b411e5ceb2498b9ca8652941752145 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:32.858162 27517 raft_consensus.cc:493] T 00000000000000000000000000000000 P 88b411e5ceb2498b9ca8652941752145 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:32.858215 27517 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 88b411e5ceb2498b9ca8652941752145 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:32.858937 27517 raft_consensus.cc:515] T 00000000000000000000000000000000 P 88b411e5ceb2498b9ca8652941752145 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "88b411e5ceb2498b9ca8652941752145" member_type: VOTER }
I20260812 06:17:32.859076 27517 leader_election.cc:304] T 00000000000000000000000000000000 P 88b411e5ceb2498b9ca8652941752145 [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: 88b411e5ceb2498b9ca8652941752145; no voters: 
I20260812 06:17:32.859297 27517 leader_election.cc:290] T 00000000000000000000000000000000 P 88b411e5ceb2498b9ca8652941752145 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:32.859426 27520 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 88b411e5ceb2498b9ca8652941752145 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:32.859683 27520 raft_consensus.cc:697] T 00000000000000000000000000000000 P 88b411e5ceb2498b9ca8652941752145 [term 1 LEADER]: Becoming Leader. State: Replica: 88b411e5ceb2498b9ca8652941752145, State: Running, Role: LEADER
I20260812 06:17:32.859779 27517 sys_catalog.cc:565] T 00000000000000000000000000000000 P 88b411e5ceb2498b9ca8652941752145 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:32.859860 27520 consensus_queue.cc:237] T 00000000000000000000000000000000 P 88b411e5ceb2498b9ca8652941752145 [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: "88b411e5ceb2498b9ca8652941752145" member_type: VOTER }
I20260812 06:17:32.860328 27523 sys_catalog.cc:455] T 00000000000000000000000000000000 P 88b411e5ceb2498b9ca8652941752145 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 88b411e5ceb2498b9ca8652941752145. Latest consensus state: current_term: 1 leader_uuid: "88b411e5ceb2498b9ca8652941752145" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "88b411e5ceb2498b9ca8652941752145" member_type: VOTER } }
I20260812 06:17:32.860430 27523 sys_catalog.cc:458] T 00000000000000000000000000000000 P 88b411e5ceb2498b9ca8652941752145 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:32.860314 27522 sys_catalog.cc:455] T 00000000000000000000000000000000 P 88b411e5ceb2498b9ca8652941752145 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "88b411e5ceb2498b9ca8652941752145" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "88b411e5ceb2498b9ca8652941752145" member_type: VOTER } }
I20260812 06:17:32.860495 27522 sys_catalog.cc:458] T 00000000000000000000000000000000 P 88b411e5ceb2498b9ca8652941752145 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:32.860817 27527 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:32.861647 27527 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:32.861923 27122 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:32.863651 27527 catalog_manager.cc:1383] Generated new cluster ID: 2270299ecb6c4b9fa19a3bf433518ba7
I20260812 06:17:32.863708 27527 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:32.879750 27527 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:32.880323 27527 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:32.887866 27527 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 88b411e5ceb2498b9ca8652941752145: Generated new TSK 0
I20260812 06:17:32.888057 27527 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:32.894697 27122 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:32.896857 27540 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:32.896852 27541 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:32.897004 27544 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:32.897158 27122 server_base.cc:1061] running on GCE node
I20260812 06:17:32.897400 27122 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:32.897459 27122 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:32.897493 27122 hybrid_clock.cc:648] HybridClock initialized: now 1786515452897492 us; error 0 us; skew 500 ppm
I20260812 06:17:32.898401 27122 webserver.cc:533] Webserver started at http://127.26.124.129:39443/ using document root <none> and password file <none>
I20260812 06:17:32.898595 27122 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:32.898672 27122 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:32.898752 27122 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:32.899174 27122 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root/instance:
uuid: "46aaa97e09b845a7aeae5fc155a826da"
format_stamp: "Formatted at 2026-08-12 06:17:32 on dist-test-slave-gkw7"
I20260812 06:17:32.900738 27122 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:32.901854 27552 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:32.902108 27122 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:32.902201 27122 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root
uuid: "46aaa97e09b845a7aeae5fc155a826da"
format_stamp: "Formatted at 2026-08-12 06:17:32 on dist-test-slave-gkw7"
I20260812 06:17:32.902293 27122 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:32.918046 27122 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:32.918520 27122 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:32.918862 27122 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:32.919374 27122 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:32.919432 27122 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:32.919483 27122 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:32.919529 27122 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:32.924183 27122 rpc_server.cc:307] RPC server started. Bound to: 127.26.124.129:41659
I20260812 06:17:32.924264 27644 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.124.129:41659 every 8 connection(s)
I20260812 06:17:32.935639 27645 heartbeater.cc:344] Connected to a master server at 127.26.124.190:41323
I20260812 06:17:32.935806 27645 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:32.936105 27645 heartbeater.cc:507] Master 127.26.124.190:41323 requested a full tablet report, sending...
I20260812 06:17:32.936863 27456 ts_manager.cc:194] Registered new tserver with Master: 46aaa97e09b845a7aeae5fc155a826da (127.26.124.129:41659)
I20260812 06:17:32.937708 27456 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:46448
I20260812 06:17:32.937882 27122 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.013196355s
I20260812 06:17:32.945590 27456 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:46450:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:32.954734 27592 tablet_service.cc:1511] Processing CreateTablet for tablet 6c65ac3869ce4fcb93001151317dffca (DEFAULT_TABLE table=heavy-update-compaction-test [id=cc1607484ae24c6ba18c24e22b214d59]), partition=
I20260812 06:17:32.955050 27592 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 6c65ac3869ce4fcb93001151317dffca. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:32.957188 27666 tablet_bootstrap.cc:492] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Bootstrap starting.
I20260812 06:17:32.958395 27666 tablet_bootstrap.cc:654] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:32.959520 27666 tablet_bootstrap.cc:492] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: No bootstrap required, opened a new log
I20260812 06:17:32.959625 27666 ts_tablet_manager.cc:1403] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:32.960093 27666 raft_consensus.cc:359] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "46aaa97e09b845a7aeae5fc155a826da" member_type: VOTER last_known_addr { host: "127.26.124.129" port: 41659 } }
I20260812 06:17:32.960189 27666 raft_consensus.cc:385] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:32.960256 27666 raft_consensus.cc:740] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 46aaa97e09b845a7aeae5fc155a826da, State: Initialized, Role: FOLLOWER
I20260812 06:17:32.960421 27666 consensus_queue.cc:260] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da [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: "46aaa97e09b845a7aeae5fc155a826da" member_type: VOTER last_known_addr { host: "127.26.124.129" port: 41659 } }
I20260812 06:17:32.960537 27666 raft_consensus.cc:399] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:32.960585 27666 raft_consensus.cc:493] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:32.960640 27666 raft_consensus.cc:3060] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:32.961448 27666 raft_consensus.cc:515] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "46aaa97e09b845a7aeae5fc155a826da" member_type: VOTER last_known_addr { host: "127.26.124.129" port: 41659 } }
I20260812 06:17:32.961732 27666 leader_election.cc:304] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da [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: 46aaa97e09b845a7aeae5fc155a826da; no voters: 
I20260812 06:17:32.961964 27666 leader_election.cc:290] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:32.962069 27670 raft_consensus.cc:2804] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:32.962297 27670 raft_consensus.cc:697] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da [term 1 LEADER]: Becoming Leader. State: Replica: 46aaa97e09b845a7aeae5fc155a826da, State: Running, Role: LEADER
I20260812 06:17:32.962354 27666 ts_tablet_manager.cc:1434] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Time spent starting tablet: real 0.003s	user 0.001s	sys 0.002s
I20260812 06:17:32.962400 27645 heartbeater.cc:499] Master 127.26.124.190:41323 was elected leader, sending a full tablet report...
I20260812 06:17:32.962446 27670 consensus_queue.cc:237] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da [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: "46aaa97e09b845a7aeae5fc155a826da" member_type: VOTER last_known_addr { host: "127.26.124.129" port: 41659 } }
I20260812 06:17:32.963843 27456 catalog_manager.cc:5719] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da reported cstate change: term changed from 0 to 1, leader changed from <none> to 46aaa97e09b845a7aeae5fc155a826da (127.26.124.129). New cstate: current_term: 1 leader_uuid: "46aaa97e09b845a7aeae5fc155a826da" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "46aaa97e09b845a7aeae5fc155a826da" member_type: VOTER last_known_addr { host: "127.26.124.129" port: 41659 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:33.025583 27122 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.055s	user 0.019s	sys 0.004s
I20260812 06:17:33.175333 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushMRSOp(6c65ac3869ce4fcb93001151317dffca): perf score=19.054940
I20260812 06:17:33.353089 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushMRSOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.177s	user 0.114s	sys 0.059s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":97,"dirs.run_cpu_time_us":163,"dirs.run_wall_time_us":848,"drs_written":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4,"lbm_write_time_us":45754,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:17:33.353971 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling LogGCOp(6c65ac3869ce4fcb93001151317dffca): free 20743831 bytes of WAL
I20260812 06:17:33.354264 27557 log_reader.cc:385] T 6c65ac3869ce4fcb93001151317dffca: removed 2 log segments from log reader
I20260812 06:17:33.354319 27557 log.cc:1079] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/6c65ac3869ce4fcb93001151317dffca/wal-000000001 (ops 1-6)
I20260812 06:17:33.354380 27557 log.cc:1079] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/6c65ac3869ce4fcb93001151317dffca/wal-000000002 (ops 7-11)
I20260812 06:17:33.358938 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: LogGCOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:17:33.359449 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=2.188937
I20260812 06:17:33.375470 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.016s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6114,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.376045 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling UndoDeltaBlockGCOp(6c65ac3869ce4fcb93001151317dffca): 16411396 bytes on disk
I20260812 06:17:33.376456 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: UndoDeltaBlockGCOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4}
I20260812 06:17:33.376881 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling MajorDeltaCompactionOp(6c65ac3869ce4fcb93001151317dffca): perf score=1.000000
I20260812 06:17:33.546639 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: MajorDeltaCompactionOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.170s	user 0.111s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":721,"lbm_read_time_us":11988,"lbm_reads_lt_1ms":460,"lbm_write_time_us":26858,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7680,"thread_start_us":345,"threads_started":5,"update_count":2000}
I20260812 06:17:33.547150 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=11.118625
I20260812 06:17:33.585578 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.038s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16100,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:33.586301 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=2.188937
I20260812 06:17:33.598372 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3940,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:33.598927 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling MajorDeltaCompactionOp(6c65ac3869ce4fcb93001151317dffca): perf score=1.000000
I20260812 06:17:33.742204 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: MajorDeltaCompactionOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.143s	user 0.091s	sys 0.051s 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":1036,"lbm_read_time_us":9028,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27867,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14592,"update_count":2000}
I20260812 06:17:33.744230 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=10.126437
I20260812 06:17:33.784130 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.040s	user 0.025s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17169,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:33.784626 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=2.188937
I20260812 06:17:33.805841 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.021s	user 0.012s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5812,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:33.806470 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling MajorDeltaCompactionOp(6c65ac3869ce4fcb93001151317dffca): perf score=1.000000
I20260812 06:17:33.957180 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: MajorDeltaCompactionOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.150s	user 0.106s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1003,"lbm_read_time_us":11182,"lbm_reads_lt_1ms":464,"lbm_write_time_us":30833,"lbm_writes_lt_1ms":443,"mutex_wait_us":425,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:17:33.958128 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=11.118625
I20260812 06:17:33.993738 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.035s	user 0.027s	sys 0.008s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":15610,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:33.994390 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=2.188937
I20260812 06:17:34.013316 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.019s	user 0.015s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6503,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:34.014079 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling MajorDeltaCompactionOp(6c65ac3869ce4fcb93001151317dffca): perf score=1.000000
I20260812 06:17:34.149231 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: MajorDeltaCompactionOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.135s	user 0.093s	sys 0.041s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672270,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1412,"lbm_read_time_us":10118,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25484,"lbm_writes_lt_1ms":443,"mutex_wait_us":1065,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":2000}
I20260812 06:17:34.150051 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=10.126437
I20260812 06:17:34.196519 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.046s	user 0.022s	sys 0.021s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15781,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:34.197209 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=2.188937
I20260812 06:17:34.217141 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.020s	user 0.017s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":7587,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.217917 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling MajorDeltaCompactionOp(6c65ac3869ce4fcb93001151317dffca): perf score=1.000000
I20260812 06:17:34.378533 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: MajorDeltaCompactionOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.160s	user 0.104s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672275,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":298,"lbm_read_time_us":9888,"lbm_reads_lt_1ms":468,"lbm_write_time_us":27921,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13952,"update_count":2000}
I20260812 06:17:34.379243 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=10.126437
I20260812 06:17:34.415186 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.036s	user 0.018s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15158,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:34.415725 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=2.188937
I20260812 06:17:34.432126 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.016s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6456,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.432585 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling MajorDeltaCompactionOp(6c65ac3869ce4fcb93001151317dffca): perf score=1.000000
I20260812 06:17:34.559563 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: MajorDeltaCompactionOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.127s	user 0.096s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":84,"lbm_read_time_us":9042,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24931,"lbm_writes_lt_1ms":443,"mutex_wait_us":1,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2000}
I20260812 06:17:34.560963 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=10.126437
I20260812 06:17:34.601745 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.040s	user 0.029s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18651,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:17:34.602298 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=2.188937
I20260812 06:17:34.623551 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.021s	user 0.004s	sys 0.012s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":7381,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.624089 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushMRSOp(6c65ac3869ce4fcb93001151317dffca): perf score=1.000000
I20260812 06:17:34.665349 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushMRSOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.041s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":297,"dirs.run_wall_time_us":1396,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2023,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:34.666141 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling UndoDeltaBlockGCOp(6c65ac3869ce4fcb93001151317dffca): 462 bytes on disk
I20260812 06:17:34.666571 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: UndoDeltaBlockGCOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:17:34.667155 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=3.181125
I20260812 06:17:34.686906 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.020s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":7041,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:34.687497 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling LogGCOp(6c65ac3869ce4fcb93001151317dffca): free 112239359 bytes of WAL
I20260812 06:17:34.687775 27557 log_reader.cc:385] T 6c65ac3869ce4fcb93001151317dffca: removed 11 log segments from log reader
I20260812 06:17:34.687848 27557 log.cc:1079] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/6c65ac3869ce4fcb93001151317dffca/wal-000000003 (ops 12-16)
I20260812 06:17:34.687906 27557 log.cc:1079] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/6c65ac3869ce4fcb93001151317dffca/wal-000000004 (ops 17-21)
I20260812 06:17:34.687963 27557 log.cc:1079] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/6c65ac3869ce4fcb93001151317dffca/wal-000000005 (ops 22-26)
I20260812 06:17:34.688006 27557 log.cc:1079] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/6c65ac3869ce4fcb93001151317dffca/wal-000000006 (ops 27-31)
I20260812 06:17:34.688045 27557 log.cc:1079] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/6c65ac3869ce4fcb93001151317dffca/wal-000000007 (ops 32-36)
I20260812 06:17:34.688086 27557 log.cc:1079] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/6c65ac3869ce4fcb93001151317dffca/wal-000000008 (ops 37-40)
I20260812 06:17:34.688112 27557 log.cc:1079] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/6c65ac3869ce4fcb93001151317dffca/wal-000000009 (ops 41-45)
I20260812 06:17:34.688133 27557 log.cc:1079] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/6c65ac3869ce4fcb93001151317dffca/wal-000000010 (ops 46-50)
I20260812 06:17:34.688164 27557 log.cc:1079] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/6c65ac3869ce4fcb93001151317dffca/wal-000000011 (ops 51-55)
I20260812 06:17:34.688202 27557 log.cc:1079] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/6c65ac3869ce4fcb93001151317dffca/wal-000000012 (ops 56-60)
I20260812 06:17:34.688241 27557 log.cc:1079] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/6c65ac3869ce4fcb93001151317dffca/wal-000000013 (ops 61-65)
I20260812 06:17:34.715417 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: LogGCOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:17:34.716022 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=2.188937
I20260812 06:17:34.730757 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.015s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4029,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:34.731189 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=2.188937
I20260812 06:17:34.741520 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3970,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.742033 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling MajorDeltaCompactionOp(6c65ac3869ce4fcb93001151317dffca): perf score=1.000000
I20260812 06:17:34.960455 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: MajorDeltaCompactionOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.218s	user 0.170s	sys 0.044s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979859,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":2142,"lbm_read_time_us":15397,"lbm_reads_lt_1ms":775,"lbm_write_time_us":44866,"lbm_writes_lt_1ms":743,"mutex_wait_us":714,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3840,"thread_start_us":81,"threads_started":1,"update_count":3500}
I20260812 06:17:34.960985 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=14.095187
I20260812 06:17:35.012570 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.051s	user 0.023s	sys 0.021s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21144,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:35.013267 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=2.188937
I20260812 06:17:35.025847 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.012s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4554,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.026378 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling MajorDeltaCompactionOp(6c65ac3869ce4fcb93001151317dffca): perf score=1.000000
I20260812 06:17:35.219667 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: MajorDeltaCompactionOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.193s	user 0.131s	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":1223,"lbm_read_time_us":12037,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29133,"lbm_writes_lt_1ms":543,"mutex_wait_us":388,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":2500}
I20260812 06:17:35.221901 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=14.095187
I20260812 06:17:35.282351 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.060s	user 0.042s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":27622,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:35.282956 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=2.188937
I20260812 06:17:35.301927 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.019s	user 0.015s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6356,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.302419 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling MajorDeltaCompactionOp(6c65ac3869ce4fcb93001151317dffca): perf score=1.000000
I20260812 06:17:35.469907 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: MajorDeltaCompactionOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.167s	user 0.139s	sys 0.020s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":189,"lbm_read_time_us":9823,"lbm_reads_lt_1ms":564,"lbm_write_time_us":33530,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":2500}
I20260812 06:17:35.470651 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=14.095187
I20260812 06:17:35.526926 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.056s	user 0.043s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23343,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:35.527383 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=2.188937
I20260812 06:17:35.539412 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4198,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.540068 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling MajorDeltaCompactionOp(6c65ac3869ce4fcb93001151317dffca): perf score=1.000000
I20260812 06:17:35.706401 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: MajorDeltaCompactionOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.166s	user 0.139s	sys 0.024s 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":222,"lbm_read_time_us":10282,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35564,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":2500}
I20260812 06:17:35.707021 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=11.118625
I20260812 06:17:35.753491 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.046s	user 0.026s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":18675,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:35.754166 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=2.188937
I20260812 06:17:35.769960 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.016s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102660,"delete_count":0,"lbm_write_time_us":4012,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":500}
I20260812 06:17:35.770505 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=2.188937
I20260812 06:17:35.784279 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.014s	user 0.008s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5128,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:35.784860 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling MajorDeltaCompactionOp(6c65ac3869ce4fcb93001151317dffca): perf score=1.000000
I20260812 06:17:35.937987 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: MajorDeltaCompactionOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.153s	user 0.120s	sys 0.032s 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":492,"lbm_read_time_us":12147,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29808,"lbm_writes_lt_1ms":543,"mutex_wait_us":380,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2500}
I20260812 06:17:35.938845 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=10.126437
I20260812 06:17:35.975531 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.035s	user 0.013s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15052,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:35.976174 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=2.188937
I20260812 06:17:35.991119 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5382,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.993259 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling MajorDeltaCompactionOp(6c65ac3869ce4fcb93001151317dffca): perf score=1.000000
I20260812 06:17:36.129995 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: MajorDeltaCompactionOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.136s	user 0.094s	sys 0.043s 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":283,"lbm_read_time_us":10091,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25784,"lbm_writes_lt_1ms":443,"mutex_wait_us":34,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16640,"update_count":2000}
I20260812 06:17:36.131671 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=10.126437
I20260812 06:17:36.186285 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.054s	user 0.027s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17546,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:36.186908 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=2.188937
I20260812 06:17:36.198084 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4297,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.198606 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushMRSOp(6c65ac3869ce4fcb93001151317dffca): perf score=1.000000
I20260812 06:17:36.245273 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushMRSOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.046s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":229,"dirs.run_wall_time_us":1464,"drs_written":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1825,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:36.246016 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling LogGCOp(6c65ac3869ce4fcb93001151317dffca): free 132571314 bytes of WAL
I20260812 06:17:36.246261 27557 log_reader.cc:385] T 6c65ac3869ce4fcb93001151317dffca: removed 13 log segments from log reader
I20260812 06:17:36.246307 27557 log.cc:1079] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/6c65ac3869ce4fcb93001151317dffca/wal-000000014 (ops 66-70)
I20260812 06:17:36.246338 27557 log.cc:1079] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/6c65ac3869ce4fcb93001151317dffca/wal-000000015 (ops 71-75)
I20260812 06:17:36.246402 27557 log.cc:1079] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/6c65ac3869ce4fcb93001151317dffca/wal-000000016 (ops 76-80)
I20260812 06:17:36.246444 27557 log.cc:1079] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/6c65ac3869ce4fcb93001151317dffca/wal-000000017 (ops 81-84)
I20260812 06:17:36.246512 27557 log.cc:1079] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/6c65ac3869ce4fcb93001151317dffca/wal-000000018 (ops 85-89)
I20260812 06:17:36.246551 27557 log.cc:1079] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/6c65ac3869ce4fcb93001151317dffca/wal-000000019 (ops 90-94)
I20260812 06:17:36.246590 27557 log.cc:1079] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/6c65ac3869ce4fcb93001151317dffca/wal-000000020 (ops 95-98)
I20260812 06:17:36.246647 27557 log.cc:1079] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/6c65ac3869ce4fcb93001151317dffca/wal-000000021 (ops 99-103)
I20260812 06:17:36.246685 27557 log.cc:1079] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/6c65ac3869ce4fcb93001151317dffca/wal-000000022 (ops 104-108)
I20260812 06:17:36.246723 27557 log.cc:1079] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/6c65ac3869ce4fcb93001151317dffca/wal-000000023 (ops 109-113)
I20260812 06:17:36.246762 27557 log.cc:1079] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/6c65ac3869ce4fcb93001151317dffca/wal-000000024 (ops 114-118)
I20260812 06:17:36.246798 27557 log.cc:1079] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/6c65ac3869ce4fcb93001151317dffca/wal-000000025 (ops 119-123)
I20260812 06:17:36.246838 27557 log.cc:1079] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/6c65ac3869ce4fcb93001151317dffca/wal-000000026 (ops 124-128)
I20260812 06:17:36.277305 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: LogGCOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.031s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:17:36.277763 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling UndoDeltaBlockGCOp(6c65ac3869ce4fcb93001151317dffca): 473 bytes on disk
I20260812 06:17:36.278357 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: UndoDeltaBlockGCOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:17:36.278925 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=3.181125
I20260812 06:17:36.294351 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.015s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4421,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:36.294871 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=2.188937
I20260812 06:17:36.305491 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3780,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:36.306877 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling MajorDeltaCompactionOp(6c65ac3869ce4fcb93001151317dffca): perf score=1.000000
I20260812 06:17:36.508965 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: MajorDeltaCompactionOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.202s	user 0.148s	sys 0.051s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877329,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1194,"lbm_read_time_us":13158,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34408,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":642,"mutex_wait_us":380,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4864,"thread_start_us":97,"threads_started":1,"update_count":3000}
I20260812 06:17:36.509907 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=15.087375
I20260812 06:17:36.563871 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.054s	user 0.031s	sys 0.020s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":24086,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:36.564559 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=2.188937
I20260812 06:17:36.578761 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5173,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:36.579397 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling MajorDeltaCompactionOp(6c65ac3869ce4fcb93001151317dffca): perf score=1.000000
I20260812 06:17:36.760455 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: MajorDeltaCompactionOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.181s	user 0.122s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774675,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":311,"lbm_read_time_us":12376,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31064,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15616,"update_count":2500}
I20260812 06:17:36.761235 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=14.095187
I20260812 06:17:36.829782 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.068s	user 0.025s	sys 0.036s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22646,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:36.830396 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=2.188937
I20260812 06:17:36.841836 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4365,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.842324 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling MajorDeltaCompactionOp(6c65ac3869ce4fcb93001151317dffca): perf score=1.000000
I20260812 06:17:37.031543 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: MajorDeltaCompactionOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.189s	user 0.147s	sys 0.040s 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":449,"lbm_read_time_us":14645,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32356,"lbm_writes_lt_1ms":543,"mutex_wait_us":297,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17920,"update_count":2500}
I20260812 06:17:37.032320 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=11.118625
I20260812 06:17:37.070773 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.038s	user 0.010s	sys 0.027s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16364,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:37.071413 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=2.188937
I20260812 06:17:37.106804 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.035s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5440,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.107473 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=2.188937
I20260812 06:17:37.122777 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.015s	user 0.008s	sys 0.006s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5598,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:37.123466 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling MajorDeltaCompactionOp(6c65ac3869ce4fcb93001151317dffca): perf score=1.000000
I20260812 06:17:37.318053 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: MajorDeltaCompactionOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.194s	user 0.118s	sys 0.077s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":154,"lbm_read_time_us":13915,"lbm_reads_lt_1ms":573,"lbm_write_time_us":34360,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:37.318833 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=14.095187
I20260812 06:17:37.373517 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.054s	user 0.027s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24446,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:37.374202 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=2.188937
I20260812 06:17:37.402184 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.028s	user 0.017s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6004,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.402807 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=1.000000
I20260812 06:17:37.410123 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.007s	user 0.005s	sys 0.002s Metrics: {"bytes_written":1969356,"delete_count":0,"lbm_write_time_us":2102,"lbm_writes_lt_1ms":51,"reinsert_count":0,"update_count":240}
I20260812 06:17:37.410692 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=1.000000
I20260812 06:17:37.417424 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.007s	user 0.003s	sys 0.002s Metrics: {"bytes_written":2133453,"delete_count":0,"lbm_write_time_us":2276,"lbm_writes_lt_1ms":55,"reinsert_count":0,"update_count":260}
I20260812 06:17:37.417950 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling MajorDeltaCompactionOp(6c65ac3869ce4fcb93001151317dffca): perf score=1.000000
I20260812 06:17:37.642925 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: MajorDeltaCompactionOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.225s	user 0.151s	sys 0.071s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877242,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":169,"lbm_read_time_us":16087,"lbm_reads_lt_1ms":674,"lbm_write_time_us":38777,"lbm_writes_lt_1ms":643,"mutex_wait_us":48,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":20736,"update_count":3000}
I20260812 06:17:37.643709 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=14.095187
I20260812 06:17:37.704632 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.061s	user 0.034s	sys 0.022s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21770,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:37.705255 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=2.188937
I20260812 06:17:37.716329 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4197,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.716818 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushMRSOp(6c65ac3869ce4fcb93001151317dffca): perf score=1.000000
I20260812 06:17:37.760563 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushMRSOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.044s	user 0.034s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":88,"dirs.run_cpu_time_us":242,"dirs.run_wall_time_us":1394,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1931,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:37.761471 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling LogGCOp(6c65ac3869ce4fcb93001151317dffca): free 112239560 bytes of WAL
I20260812 06:17:37.761747 27557 log_reader.cc:385] T 6c65ac3869ce4fcb93001151317dffca: removed 11 log segments from log reader
I20260812 06:17:37.761818 27557 log.cc:1079] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/6c65ac3869ce4fcb93001151317dffca/wal-000000027 (ops 129-133)
I20260812 06:17:37.761858 27557 log.cc:1079] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/6c65ac3869ce4fcb93001151317dffca/wal-000000028 (ops 134-138)
I20260812 06:17:37.761895 27557 log.cc:1079] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/6c65ac3869ce4fcb93001151317dffca/wal-000000029 (ops 139-143)
I20260812 06:17:37.761924 27557 log.cc:1079] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/6c65ac3869ce4fcb93001151317dffca/wal-000000030 (ops 144-148)
I20260812 06:17:37.761946 27557 log.cc:1079] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/6c65ac3869ce4fcb93001151317dffca/wal-000000031 (ops 149-153)
I20260812 06:17:37.761974 27557 log.cc:1079] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/6c65ac3869ce4fcb93001151317dffca/wal-000000032 (ops 154-158)
I20260812 06:17:37.762007 27557 log.cc:1079] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/6c65ac3869ce4fcb93001151317dffca/wal-000000033 (ops 159-163)
I20260812 06:17:37.762041 27557 log.cc:1079] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/6c65ac3869ce4fcb93001151317dffca/wal-000000034 (ops 164-168)
I20260812 06:17:37.762063 27557 log.cc:1079] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/6c65ac3869ce4fcb93001151317dffca/wal-000000035 (ops 169-172)
I20260812 06:17:37.762094 27557 log.cc:1079] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/6c65ac3869ce4fcb93001151317dffca/wal-000000036 (ops 173-177)
I20260812 06:17:37.762122 27557 log.cc:1079] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: Deleting log segment in path: /tmp/dist-test-taskITU9ey/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515447152442-27122-0/minicluster-data/ts-0-root/wals/6c65ac3869ce4fcb93001151317dffca/wal-000000037 (ops 178-182)
I20260812 06:17:37.791762 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: LogGCOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.030s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:17:37.792348 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling UndoDeltaBlockGCOp(6c65ac3869ce4fcb93001151317dffca): 447 bytes on disk
I20260812 06:17:37.792924 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: UndoDeltaBlockGCOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:17:37.793754 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=2.188937
I20260812 06:17:37.818383 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.024s	user 0.015s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6268,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.818969 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=2.188937
I20260812 06:17:37.829684 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3980,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.830312 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling MajorDeltaCompactionOp(6c65ac3869ce4fcb93001151317dffca): perf score=1.000000
I20260812 06:17:38.048309 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: MajorDeltaCompactionOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.218s	user 0.152s	sys 0.065s 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":1072,"lbm_read_time_us":15297,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38063,"lbm_writes_lt_1ms":743,"mutex_wait_us":286,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":10496,"thread_start_us":95,"threads_started":1,"update_count":3500}
I20260812 06:17:38.049054 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=18.063937
I20260812 06:17:38.107558 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.058s	user 0.052s	sys 0.004s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":24918,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:38.108292 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=2.188937
I20260812 06:17:38.130635 27122 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.105s	user 1.898s	sys 0.161s
I20260812 06:17:38.132308 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.024s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5066,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:38.132763 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca): perf score=2.188937
I20260812 06:17:38.148017 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: FlushDeltaMemStoresOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.015s	user 0.003s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6330,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":500}
I20260812 06:17:38.148464 27647 maintenance_manager.cc:419] P 46aaa97e09b845a7aeae5fc155a826da: Scheduling MajorDeltaCompactionOp(6c65ac3869ce4fcb93001151317dffca): perf score=1.000000
I20260812 06:17:38.192152 27122 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.061s	user 0.001s	sys 0.000s
I20260812 06:17:38.192688 27122 tablet_server.cc:179] TabletServer@127.26.124.129:0 shutting down...
I20260812 06:17:38.295306 27557 maintenance_manager.cc:643] P 46aaa97e09b845a7aeae5fc155a826da: MajorDeltaCompactionOp(6c65ac3869ce4fcb93001151317dffca) complete. Timing: real 0.147s	user 0.098s	sys 0.048s Metrics: {"cfile_cache_hit":361,"cfile_cache_hit_bytes":14731062,"cfile_cache_miss":372,"cfile_cache_miss_bytes":18248572,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":738,"lbm_read_time_us":7032,"lbm_reads_lt_1ms":404,"lbm_write_time_us":33729,"lbm_writes_lt_1ms":743,"mutex_wait_us":161,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":3500}
I20260812 06:17:38.296062 27122 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:38.296347 27122 tablet_replica.cc:333] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da: stopping tablet replica
I20260812 06:17:38.296519 27122 raft_consensus.cc:2243] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:38.296715 27122 raft_consensus.cc:2272] T 6c65ac3869ce4fcb93001151317dffca P 46aaa97e09b845a7aeae5fc155a826da [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:38.312635 27122 tablet_server.cc:196] TabletServer@127.26.124.129:0 shutdown complete.
I20260812 06:17:38.357388 27122 master.cc:562] Master@127.26.124.190:41323 shutting down...
I20260812 06:17:38.360778 27122 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 88b411e5ceb2498b9ca8652941752145 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:38.360956 27122 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 88b411e5ceb2498b9ca8652941752145 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:38.361007 27122 tablet_replica.cc:333] T 00000000000000000000000000000000 P 88b411e5ceb2498b9ca8652941752145: stopping tablet replica
I20260812 06:17:38.373857 27122 master.cc:584] Master@127.26.124.190:41323 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5676 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11307 ms total)

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