[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:17:33.391080 30740 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.30.5.62:39283
I20260812 06:17:33.391988 30740 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:17:33.392552 30740 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:33.398541 30752 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:33.398566 30750 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:33.398790 30754 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:33.398649 30740 server_base.cc:1061] running on GCE node
I20260812 06:17:33.399236 30740 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:33.399331 30740 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:33.399372 30740 hybrid_clock.cc:648] HybridClock initialized: now 1786515453399370 us; error 0 us; skew 500 ppm
I20260812 06:17:33.400955 30740 webserver.cc:533] Webserver started at http://127.30.5.62:36555/ using document root <none> and password file <none>
I20260812 06:17:33.401473 30740 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:33.401535 30740 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:33.401751 30740 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:33.403257 30740 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/master-0-root/instance:
uuid: "859ac024cced475283ab797a6550e147"
format_stamp: "Formatted at 2026-08-12 06:17:33 on dist-test-slave-266d"
I20260812 06:17:33.406347 30740 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.001s	sys 0.003s
I20260812 06:17:33.408151 30766 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:33.409027 30740 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.001s	sys 0.001s
I20260812 06:17:33.409155 30740 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/master-0-root
uuid: "859ac024cced475283ab797a6550e147"
format_stamp: "Formatted at 2026-08-12 06:17:33 on dist-test-slave-266d"
I20260812 06:17:33.409235 30740 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:33.417812 30740 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:33.418283 30740 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:17:33.418411 30740 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:33.424974 30740 rpc_server.cc:307] RPC server started. Bound to: 127.30.5.62:39283
I20260812 06:17:33.424974 30857 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.30.5.62:39283 every 8 connection(s)
I20260812 06:17:33.426960 30858 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:33.431851 30858 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 859ac024cced475283ab797a6550e147: Bootstrap starting.
I20260812 06:17:33.434032 30858 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 859ac024cced475283ab797a6550e147: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:33.434828 30858 log.cc:826] T 00000000000000000000000000000000 P 859ac024cced475283ab797a6550e147: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:33.436245 30858 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 859ac024cced475283ab797a6550e147: No bootstrap required, opened a new log
I20260812 06:17:33.438844 30858 raft_consensus.cc:359] T 00000000000000000000000000000000 P 859ac024cced475283ab797a6550e147 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "859ac024cced475283ab797a6550e147" member_type: VOTER }
I20260812 06:17:33.439023 30858 raft_consensus.cc:385] T 00000000000000000000000000000000 P 859ac024cced475283ab797a6550e147 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:33.439092 30858 raft_consensus.cc:740] T 00000000000000000000000000000000 P 859ac024cced475283ab797a6550e147 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 859ac024cced475283ab797a6550e147, State: Initialized, Role: FOLLOWER
I20260812 06:17:33.439601 30858 consensus_queue.cc:260] T 00000000000000000000000000000000 P 859ac024cced475283ab797a6550e147 [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: "859ac024cced475283ab797a6550e147" member_type: VOTER }
I20260812 06:17:33.439733 30858 raft_consensus.cc:399] T 00000000000000000000000000000000 P 859ac024cced475283ab797a6550e147 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:33.439806 30858 raft_consensus.cc:493] T 00000000000000000000000000000000 P 859ac024cced475283ab797a6550e147 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:33.439919 30858 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 859ac024cced475283ab797a6550e147 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:33.440604 30858 raft_consensus.cc:515] T 00000000000000000000000000000000 P 859ac024cced475283ab797a6550e147 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "859ac024cced475283ab797a6550e147" member_type: VOTER }
I20260812 06:17:33.440997 30858 leader_election.cc:304] T 00000000000000000000000000000000 P 859ac024cced475283ab797a6550e147 [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: 859ac024cced475283ab797a6550e147; no voters: 
I20260812 06:17:33.441285 30858 leader_election.cc:290] T 00000000000000000000000000000000 P 859ac024cced475283ab797a6550e147 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:33.441388 30862 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 859ac024cced475283ab797a6550e147 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:33.441586 30862 raft_consensus.cc:697] T 00000000000000000000000000000000 P 859ac024cced475283ab797a6550e147 [term 1 LEADER]: Becoming Leader. State: Replica: 859ac024cced475283ab797a6550e147, State: Running, Role: LEADER
I20260812 06:17:33.441952 30862 consensus_queue.cc:237] T 00000000000000000000000000000000 P 859ac024cced475283ab797a6550e147 [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: "859ac024cced475283ab797a6550e147" member_type: VOTER }
I20260812 06:17:33.442155 30858 sys_catalog.cc:565] T 00000000000000000000000000000000 P 859ac024cced475283ab797a6550e147 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:33.443686 30865 sys_catalog.cc:455] T 00000000000000000000000000000000 P 859ac024cced475283ab797a6550e147 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "859ac024cced475283ab797a6550e147" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "859ac024cced475283ab797a6550e147" member_type: VOTER } }
I20260812 06:17:33.443806 30865 sys_catalog.cc:458] T 00000000000000000000000000000000 P 859ac024cced475283ab797a6550e147 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:33.444037 30866 sys_catalog.cc:455] T 00000000000000000000000000000000 P 859ac024cced475283ab797a6550e147 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 859ac024cced475283ab797a6550e147. Latest consensus state: current_term: 1 leader_uuid: "859ac024cced475283ab797a6550e147" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "859ac024cced475283ab797a6550e147" member_type: VOTER } }
I20260812 06:17:33.444118 30866 sys_catalog.cc:458] T 00000000000000000000000000000000 P 859ac024cced475283ab797a6550e147 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:33.444219 30740 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:17:33.445916 30881 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 859ac024cced475283ab797a6550e147: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:17:33.445979 30881 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:17:33.446075 30879 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:33.446736 30879 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:33.450593 30879 catalog_manager.cc:1383] Generated new cluster ID: 40051b8befd04dc7bfcc36f0621268c1
I20260812 06:17:33.450652 30879 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:33.466879 30879 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:33.467605 30879 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:33.473246 30879 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 859ac024cced475283ab797a6550e147: Generated new TSK 0
I20260812 06:17:33.473749 30879 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:33.476761 30740 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:33.479391 30886 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:33.479389 30887 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:33.479442 30890 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:33.479638 30740 server_base.cc:1061] running on GCE node
I20260812 06:17:33.479856 30740 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:33.479912 30740 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:33.479933 30740 hybrid_clock.cc:648] HybridClock initialized: now 1786515453479933 us; error 0 us; skew 500 ppm
I20260812 06:17:33.480840 30740 webserver.cc:533] Webserver started at http://127.30.5.1:42979/ using document root <none> and password file <none>
I20260812 06:17:33.480998 30740 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:33.481053 30740 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:33.481160 30740 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:33.481555 30740 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/instance:
uuid: "7625e313ba4741949f0904f58db35b5e"
format_stamp: "Formatted at 2026-08-12 06:17:33 on dist-test-slave-266d"
I20260812 06:17:33.483242 30740 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:33.484251 30898 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:33.484512 30740 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:33.484591 30740 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root
uuid: "7625e313ba4741949f0904f58db35b5e"
format_stamp: "Formatted at 2026-08-12 06:17:33 on dist-test-slave-266d"
I20260812 06:17:33.484656 30740 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-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:33.513231 30740 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:33.513684 30740 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:33.514189 30740 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:33.515177 30740 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:33.515244 30740 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:33.515305 30740 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:33.515334 30740 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:33.521867 30740 rpc_server.cc:307] RPC server started. Bound to: 127.30.5.1:46425
I20260812 06:17:33.521891 30997 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.30.5.1:46425 every 8 connection(s)
I20260812 06:17:33.531031 30998 heartbeater.cc:344] Connected to a master server at 127.30.5.62:39283
I20260812 06:17:33.531246 30998 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:33.531637 30998 heartbeater.cc:507] Master 127.30.5.62:39283 requested a full tablet report, sending...
I20260812 06:17:33.532931 30794 ts_manager.cc:194] Registered new tserver with Master: 7625e313ba4741949f0904f58db35b5e (127.30.5.1:46425)
I20260812 06:17:33.533321 30740 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.01078066s
I20260812 06:17:33.534134 30794 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:60488
I20260812 06:17:33.541971 30794 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:60494:
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:33.555720 30940 tablet_service.cc:1511] Processing CreateTablet for tablet d40ea4b9f8f84dfbbef4203f5282d67b (DEFAULT_TABLE table=heavy-update-compaction-test [id=b6721707a7bb48c3aef1168c0ec2eb25]), partition=
I20260812 06:17:33.556104 30940 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet d40ea4b9f8f84dfbbef4203f5282d67b. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:33.558159 31020 tablet_bootstrap.cc:492] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Bootstrap starting.
I20260812 06:17:33.559139 31020 tablet_bootstrap.cc:654] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:33.560107 31020 tablet_bootstrap.cc:492] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: No bootstrap required, opened a new log
I20260812 06:17:33.560197 31020 ts_tablet_manager.cc:1403] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:33.560581 31020 raft_consensus.cc:359] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7625e313ba4741949f0904f58db35b5e" member_type: VOTER last_known_addr { host: "127.30.5.1" port: 46425 } }
I20260812 06:17:33.560674 31020 raft_consensus.cc:385] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:33.560706 31020 raft_consensus.cc:740] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7625e313ba4741949f0904f58db35b5e, State: Initialized, Role: FOLLOWER
I20260812 06:17:33.560833 31020 consensus_queue.cc:260] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e [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: "7625e313ba4741949f0904f58db35b5e" member_type: VOTER last_known_addr { host: "127.30.5.1" port: 46425 } }
I20260812 06:17:33.560922 31020 raft_consensus.cc:399] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:33.560966 31020 raft_consensus.cc:493] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:33.561014 31020 raft_consensus.cc:3060] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:33.561712 31020 raft_consensus.cc:515] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7625e313ba4741949f0904f58db35b5e" member_type: VOTER last_known_addr { host: "127.30.5.1" port: 46425 } }
I20260812 06:17:33.561836 31020 leader_election.cc:304] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e [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: 7625e313ba4741949f0904f58db35b5e; no voters: 
I20260812 06:17:33.562006 31020 leader_election.cc:290] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:33.562107 31024 raft_consensus.cc:2804] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:33.562306 31024 raft_consensus.cc:697] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e [term 1 LEADER]: Becoming Leader. State: Replica: 7625e313ba4741949f0904f58db35b5e, State: Running, Role: LEADER
I20260812 06:17:33.562747 30998 heartbeater.cc:499] Master 127.30.5.62:39283 was elected leader, sending a full tablet report...
I20260812 06:17:33.562901 31024 consensus_queue.cc:237] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e [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: "7625e313ba4741949f0904f58db35b5e" member_type: VOTER last_known_addr { host: "127.30.5.1" port: 46425 } }
I20260812 06:17:33.562409 31020 ts_tablet_manager.cc:1434] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:17:33.565636 30794 catalog_manager.cc:5719] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e reported cstate change: term changed from 0 to 1, leader changed from <none> to 7625e313ba4741949f0904f58db35b5e (127.30.5.1). New cstate: current_term: 1 leader_uuid: "7625e313ba4741949f0904f58db35b5e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7625e313ba4741949f0904f58db35b5e" member_type: VOTER last_known_addr { host: "127.30.5.1" port: 46425 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:33.626854 30740 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.055s	user 0.016s	sys 0.010s
I20260812 06:17:33.773155 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushMRSOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=20.047128
I20260812 06:17:33.957701 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushMRSOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.184s	user 0.117s	sys 0.064s Metrics: {"bytes_written":12717736,"cfile_init":1,"compiler_manager_pool.queue_time_us":735,"delete_count":0,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":200,"dirs.run_wall_time_us":961,"drs_written":1,"lbm_read_time_us":115,"lbm_reads_lt_1ms":4,"lbm_write_time_us":43633,"lbm_writes_lt_1ms":867,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"thread_start_us":99,"threads_started":1,"update_count":1550}
I20260812 06:17:33.958652 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling LogGCOp(d40ea4b9f8f84dfbbef4203f5282d67b): free 20743880 bytes of WAL
I20260812 06:17:33.958926 30905 log_reader.cc:385] T d40ea4b9f8f84dfbbef4203f5282d67b: removed 2 log segments from log reader
I20260812 06:17:33.958983 30905 log.cc:1079] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/d40ea4b9f8f84dfbbef4203f5282d67b/wal-000000001 (ops 1-6)
I20260812 06:17:33.959034 30905 log.cc:1079] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/d40ea4b9f8f84dfbbef4203f5282d67b/wal-000000002 (ops 7-11)
I20260812 06:17:33.962584 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: LogGCOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.004s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:17:33.962879 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=2.188937
I20260812 06:17:33.972672 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.010s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3172,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:33.973161 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling UndoDeltaBlockGCOp(d40ea4b9f8f84dfbbef4203f5282d67b): 20513815 bytes on disk
I20260812 06:17:33.973801 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: UndoDeltaBlockGCOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4}
I20260812 06:17:33.974205 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling MajorDeltaCompactionOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=1.000000
I20260812 06:17:34.113267 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: MajorDeltaCompactionOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.139s	user 0.089s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713264,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":580,"lbm_read_time_us":9260,"lbm_reads_lt_1ms":468,"lbm_write_time_us":22177,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":303,"threads_started":5,"update_count":2000}
I20260812 06:17:34.113698 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=10.126437
I20260812 06:17:34.155962 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.042s	user 0.013s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13633,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:34.156400 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=2.188937
I20260812 06:17:34.166034 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3492,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.167188 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling MajorDeltaCompactionOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=1.000000
I20260812 06:17:34.287101 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: MajorDeltaCompactionOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.120s	user 0.087s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":874,"lbm_read_time_us":9652,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20464,"lbm_writes_lt_1ms":443,"mutex_wait_us":46,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:17:34.287580 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=10.126437
I20260812 06:17:34.329813 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.042s	user 0.032s	sys 0.000s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13607,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:34.330327 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=2.188937
I20260812 06:17:34.340119 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3604,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.340617 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling MajorDeltaCompactionOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=1.000000
I20260812 06:17:34.452702 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: MajorDeltaCompactionOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.112s	user 0.088s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":833,"lbm_read_time_us":7662,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20575,"lbm_writes_lt_1ms":443,"mutex_wait_us":306,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:17:34.453256 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=10.126437
I20260812 06:17:34.492986 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.040s	user 0.021s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12173,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:34.493481 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=2.188937
I20260812 06:17:34.508183 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5584,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.508630 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling MajorDeltaCompactionOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=1.000000
I20260812 06:17:34.653218 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: MajorDeltaCompactionOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.144s	user 0.111s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":530,"lbm_read_time_us":10606,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22636,"lbm_writes_lt_1ms":443,"mutex_wait_us":248,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14848,"update_count":2000}
I20260812 06:17:34.653714 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=10.126437
I20260812 06:17:34.696678 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.043s	user 0.020s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16123,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:34.697180 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=2.188937
I20260812 06:17:34.706512 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3461,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.706909 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling MajorDeltaCompactionOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=1.000000
I20260812 06:17:34.833559 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: MajorDeltaCompactionOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.126s	user 0.105s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":604,"lbm_read_time_us":8214,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25808,"lbm_writes_lt_1ms":443,"mutex_wait_us":56,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2000}
I20260812 06:17:34.834092 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=10.126437
I20260812 06:17:34.872793 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.039s	user 0.020s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13534,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:34.873311 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=2.188937
I20260812 06:17:34.887650 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.014s	user 0.004s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5738,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.888163 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling MajorDeltaCompactionOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=1.000000
I20260812 06:17:35.003386 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: MajorDeltaCompactionOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.115s	user 0.087s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":784,"lbm_read_time_us":7562,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22802,"lbm_writes_lt_1ms":443,"mutex_wait_us":240,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":2000}
I20260812 06:17:35.003916 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=10.126437
I20260812 06:17:35.048734 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.045s	user 0.015s	sys 0.024s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13697,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:35.049291 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=2.188937
I20260812 06:17:35.059321 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3852,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.059685 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushMRSOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=1.000000
I20260812 06:17:35.096994 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushMRSOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.037s	user 0.020s	sys 0.004s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":201,"dirs.run_wall_time_us":1214,"drs_written":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1296,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:35.097777 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling LogGCOp(d40ea4b9f8f84dfbbef4203f5282d67b): free 112239247 bytes of WAL
I20260812 06:17:35.097995 30905 log_reader.cc:385] T d40ea4b9f8f84dfbbef4203f5282d67b: removed 11 log segments from log reader
I20260812 06:17:35.098043 30905 log.cc:1079] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/d40ea4b9f8f84dfbbef4203f5282d67b/wal-000000003 (ops 12-16)
I20260812 06:17:35.098073 30905 log.cc:1079] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/d40ea4b9f8f84dfbbef4203f5282d67b/wal-000000004 (ops 17-21)
I20260812 06:17:35.098104 30905 log.cc:1079] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/d40ea4b9f8f84dfbbef4203f5282d67b/wal-000000005 (ops 22-26)
I20260812 06:17:35.098137 30905 log.cc:1079] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/d40ea4b9f8f84dfbbef4203f5282d67b/wal-000000006 (ops 27-30)
I20260812 06:17:35.098169 30905 log.cc:1079] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/d40ea4b9f8f84dfbbef4203f5282d67b/wal-000000007 (ops 31-35)
I20260812 06:17:35.098201 30905 log.cc:1079] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/d40ea4b9f8f84dfbbef4203f5282d67b/wal-000000008 (ops 36-40)
I20260812 06:17:35.098233 30905 log.cc:1079] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/d40ea4b9f8f84dfbbef4203f5282d67b/wal-000000009 (ops 41-45)
I20260812 06:17:35.098265 30905 log.cc:1079] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/d40ea4b9f8f84dfbbef4203f5282d67b/wal-000000010 (ops 46-50)
I20260812 06:17:35.098305 30905 log.cc:1079] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/d40ea4b9f8f84dfbbef4203f5282d67b/wal-000000011 (ops 51-55)
I20260812 06:17:35.098340 30905 log.cc:1079] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/d40ea4b9f8f84dfbbef4203f5282d67b/wal-000000012 (ops 56-60)
I20260812 06:17:35.098361 30905 log.cc:1079] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/d40ea4b9f8f84dfbbef4203f5282d67b/wal-000000013 (ops 61-65)
I20260812 06:17:35.118499 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: LogGCOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.021s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:17:35.118844 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling UndoDeltaBlockGCOp(d40ea4b9f8f84dfbbef4203f5282d67b): 447 bytes on disk
I20260812 06:17:35.119233 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: UndoDeltaBlockGCOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:17:35.119688 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=3.181125
I20260812 06:17:35.141333 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.021s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4970,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:35.141817 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=2.188937
I20260812 06:17:35.154717 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4728,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:35.155179 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling MajorDeltaCompactionOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=1.000000
I20260812 06:17:35.349335 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: MajorDeltaCompactionOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.194s	user 0.136s	sys 0.055s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918325,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2472,"lbm_read_time_us":13981,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33578,"lbm_writes_lt_1ms":643,"mutex_wait_us":1714,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":73,"threads_started":1,"update_count":3000}
I20260812 06:17:35.349787 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=14.095187
I20260812 06:17:35.406903 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.057s	user 0.030s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23615,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:35.407435 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=2.188937
I20260812 06:17:35.422454 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5598,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.422884 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling MajorDeltaCompactionOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=1.000000
I20260812 06:17:35.579890 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: MajorDeltaCompactionOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.157s	user 0.103s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":808,"lbm_read_time_us":10049,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26395,"lbm_writes_lt_1ms":543,"mutex_wait_us":39,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":2500}
I20260812 06:17:35.580392 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=14.095187
I20260812 06:17:35.635083 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.055s	user 0.018s	sys 0.031s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19340,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:35.635568 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=2.188937
I20260812 06:17:35.645545 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3719,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.645941 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling MajorDeltaCompactionOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=1.000000
I20260812 06:17:35.802489 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: MajorDeltaCompactionOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.156s	user 0.102s	sys 0.054s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":205,"lbm_read_time_us":10870,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27789,"lbm_writes_lt_1ms":543,"mutex_wait_us":18,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9600,"update_count":2500}
I20260812 06:17:35.803097 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=10.126437
I20260812 06:17:35.834455 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.031s	user 0.021s	sys 0.009s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":13417,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:35.834892 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=2.188937
I20260812 06:17:35.857916 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.023s	user 0.000s	sys 0.022s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6853,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.858355 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling MajorDeltaCompactionOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=1.000000
I20260812 06:17:35.990115 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: MajorDeltaCompactionOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.132s	user 0.090s	sys 0.041s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1252,"lbm_read_time_us":8011,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22867,"lbm_writes_lt_1ms":443,"mutex_wait_us":483,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9600,"update_count":2000}
I20260812 06:17:35.990666 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=10.126437
I20260812 06:17:36.034138 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.040s	user 0.007s	sys 0.032s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":15561,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:36.034786 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=2.188937
I20260812 06:17:36.056111 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.021s	user 0.009s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4287,"lbm_writes_lt_1ms":93,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":450}
I20260812 06:17:36.056612 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=2.188937
I20260812 06:17:36.066164 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3506,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.066713 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling MajorDeltaCompactionOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=1.000000
I20260812 06:17:36.212724 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: MajorDeltaCompactionOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.146s	user 0.106s	sys 0.036s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815796,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":212,"lbm_read_time_us":11194,"lbm_reads_lt_1ms":573,"lbm_write_time_us":26644,"lbm_writes_lt_1ms":543,"mutex_wait_us":30,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8192,"update_count":2500}
I20260812 06:17:36.213397 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=11.118625
I20260812 06:17:36.242033 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.028s	user 0.019s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":11412,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:36.242736 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=2.188937
I20260812 06:17:36.266896 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.024s	user 0.005s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4095,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:36.267419 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=2.188937
I20260812 06:17:36.281708 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.014s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5257,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.282163 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling MajorDeltaCompactionOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=1.000000
I20260812 06:17:36.408020 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: MajorDeltaCompactionOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.126s	user 0.095s	sys 0.029s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":925,"lbm_read_time_us":8638,"lbm_reads_lt_1ms":573,"lbm_write_time_us":24846,"lbm_writes_lt_1ms":543,"mutex_wait_us":276,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2500}
I20260812 06:17:36.408511 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=11.118625
I20260812 06:17:36.439066 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.030s	user 0.021s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":12707,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:36.439567 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=2.188937
I20260812 06:17:36.453859 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5373,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:36.454452 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushMRSOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=1.000000
I20260812 06:17:36.481772 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushMRSOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.027s	user 0.023s	sys 0.004s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":44,"dirs.run_cpu_time_us":196,"dirs.run_wall_time_us":1205,"drs_written":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1751,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:36.482458 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling LogGCOp(d40ea4b9f8f84dfbbef4203f5282d67b): free 133024419 bytes of WAL
I20260812 06:17:36.482688 30905 log_reader.cc:385] T d40ea4b9f8f84dfbbef4203f5282d67b: removed 13 log segments from log reader
I20260812 06:17:36.482748 30905 log.cc:1079] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/d40ea4b9f8f84dfbbef4203f5282d67b/wal-000000014 (ops 66-70)
I20260812 06:17:36.482791 30905 log.cc:1079] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/d40ea4b9f8f84dfbbef4203f5282d67b/wal-000000015 (ops 71-75)
I20260812 06:17:36.482820 30905 log.cc:1079] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/d40ea4b9f8f84dfbbef4203f5282d67b/wal-000000016 (ops 76-80)
I20260812 06:17:36.482849 30905 log.cc:1079] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/d40ea4b9f8f84dfbbef4203f5282d67b/wal-000000017 (ops 81-85)
I20260812 06:17:36.482880 30905 log.cc:1079] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/d40ea4b9f8f84dfbbef4203f5282d67b/wal-000000018 (ops 86-90)
I20260812 06:17:36.482909 30905 log.cc:1079] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/d40ea4b9f8f84dfbbef4203f5282d67b/wal-000000019 (ops 91-95)
I20260812 06:17:36.482934 30905 log.cc:1079] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/d40ea4b9f8f84dfbbef4203f5282d67b/wal-000000020 (ops 96-100)
I20260812 06:17:36.482959 30905 log.cc:1079] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/d40ea4b9f8f84dfbbef4203f5282d67b/wal-000000021 (ops 101-105)
I20260812 06:17:36.482986 30905 log.cc:1079] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/d40ea4b9f8f84dfbbef4203f5282d67b/wal-000000022 (ops 106-110)
I20260812 06:17:36.483019 30905 log.cc:1079] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/d40ea4b9f8f84dfbbef4203f5282d67b/wal-000000023 (ops 111-114)
I20260812 06:17:36.483048 30905 log.cc:1079] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/d40ea4b9f8f84dfbbef4203f5282d67b/wal-000000024 (ops 115-119)
I20260812 06:17:36.483073 30905 log.cc:1079] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/d40ea4b9f8f84dfbbef4203f5282d67b/wal-000000025 (ops 120-124)
I20260812 06:17:36.483098 30905 log.cc:1079] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/d40ea4b9f8f84dfbbef4203f5282d67b/wal-000000026 (ops 125-129)
I20260812 06:17:36.507387 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: LogGCOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.025s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:17:36.507973 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=5.165500
I20260812 06:17:36.527086 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.019s	user 0.013s	sys 0.004s Metrics: {"bytes_written":6400018,"delete_count":0,"lbm_write_time_us":7482,"lbm_writes_lt_1ms":159,"reinsert_count":0,"update_count":780}
I20260812 06:17:36.527571 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling UndoDeltaBlockGCOp(d40ea4b9f8f84dfbbef4203f5282d67b): 481 bytes on disk
I20260812 06:17:36.528128 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: UndoDeltaBlockGCOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":83,"lbm_reads_lt_1ms":4}
I20260812 06:17:36.528674 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=1.000000
I20260812 06:17:36.537601 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.009s	user 0.007s	sys 0.000s Metrics: {"bytes_written":1805252,"delete_count":0,"lbm_write_time_us":2449,"lbm_writes_lt_1ms":47,"reinsert_count":0,"update_count":220}
I20260812 06:17:36.538460 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling MajorDeltaCompactionOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=1.000000
I20260812 06:17:36.696175 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: MajorDeltaCompactionOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.158s	user 0.118s	sys 0.039s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918272,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":159,"lbm_read_time_us":10140,"lbm_reads_lt_1ms":666,"lbm_write_time_us":32420,"lbm_writes_lt_1ms":643,"mutex_wait_us":41,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":52480,"thread_start_us":76,"threads_started":1,"update_count":3000}
I20260812 06:17:36.696719 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=14.095187
I20260812 06:17:36.737238 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.040s	user 0.037s	sys 0.003s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17679,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:36.737922 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=2.188937
I20260812 06:17:36.754118 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.016s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5155,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.754654 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling MajorDeltaCompactionOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=1.000000
I20260812 06:17:36.895573 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: MajorDeltaCompactionOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.141s	user 0.099s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":720,"lbm_read_time_us":9510,"lbm_reads_lt_1ms":564,"lbm_write_time_us":25391,"lbm_writes_lt_1ms":543,"mutex_wait_us":276,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:36.896226 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=14.095187
I20260812 06:17:36.953709 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.057s	user 0.032s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22591,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:36.954248 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=2.188937
I20260812 06:17:36.963872 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.009s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3577,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.964347 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling MajorDeltaCompactionOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=1.000000
I20260812 06:17:37.132356 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: MajorDeltaCompactionOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.168s	user 0.113s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":211,"lbm_read_time_us":11832,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28225,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:17:37.133075 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=14.095187
I20260812 06:17:37.185654 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.052s	user 0.031s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23342,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:37.186184 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=2.188937
I20260812 06:17:37.195860 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3750,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.196257 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling MajorDeltaCompactionOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=1.000000
I20260812 06:17:37.345631 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: MajorDeltaCompactionOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.149s	user 0.106s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":571,"lbm_read_time_us":11438,"lbm_reads_lt_1ms":572,"lbm_write_time_us":24453,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:17:37.346101 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=14.095187
I20260812 06:17:37.411353 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.065s	user 0.031s	sys 0.031s Metrics: {"bytes_written":16409888,"delete_count":0,"lbm_write_time_us":22709,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:37.411919 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=2.188937
I20260812 06:17:37.421758 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3771,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.422154 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling MajorDeltaCompactionOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=1.000000
I20260812 06:17:37.591010 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: MajorDeltaCompactionOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.169s	user 0.093s	sys 0.066s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815669,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":697,"lbm_read_time_us":12917,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":571,"lbm_write_time_us":26183,"lbm_writes_lt_1ms":543,"mutex_wait_us":323,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:37.591606 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=14.095187
I20260812 06:17:37.642045 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.050s	user 0.034s	sys 0.009s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18833,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:17:37.642541 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=2.188937
I20260812 06:17:37.664542 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.022s	user 0.015s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5655,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.664986 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling MajorDeltaCompactionOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=1.000000
I20260812 06:17:37.836014 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: MajorDeltaCompactionOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.171s	user 0.099s	sys 0.066s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":551,"lbm_read_time_us":11777,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27431,"lbm_writes_lt_1ms":543,"mutex_wait_us":269,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:17:37.836524 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=14.095187
I20260812 06:17:37.886162 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.049s	user 0.024s	sys 0.019s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":19685,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:37.886737 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=2.188937
I20260812 06:17:37.896827 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3691,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.897526 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushMRSOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=1.000000
I20260812 06:17:37.933439 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushMRSOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.036s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":53,"dirs.run_cpu_time_us":174,"dirs.run_wall_time_us":1179,"drs_written":1,"lbm_read_time_us":34,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1958,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:37.934068 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling LogGCOp(d40ea4b9f8f84dfbbef4203f5282d67b): free 128867676 bytes of WAL
I20260812 06:17:37.934279 30905 log_reader.cc:385] T d40ea4b9f8f84dfbbef4203f5282d67b: removed 13 log segments from log reader
I20260812 06:17:37.934329 30905 log.cc:1079] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/d40ea4b9f8f84dfbbef4203f5282d67b/wal-000000027 (ops 130-134)
I20260812 06:17:37.934365 30905 log.cc:1079] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/d40ea4b9f8f84dfbbef4203f5282d67b/wal-000000028 (ops 135-138)
I20260812 06:17:37.934389 30905 log.cc:1079] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/d40ea4b9f8f84dfbbef4203f5282d67b/wal-000000029 (ops 139-143)
I20260812 06:17:37.934412 30905 log.cc:1079] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/d40ea4b9f8f84dfbbef4203f5282d67b/wal-000000030 (ops 144-148)
I20260812 06:17:37.934445 30905 log.cc:1079] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/d40ea4b9f8f84dfbbef4203f5282d67b/wal-000000031 (ops 149-153)
I20260812 06:17:37.934473 30905 log.cc:1079] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/d40ea4b9f8f84dfbbef4203f5282d67b/wal-000000032 (ops 154-158)
I20260812 06:17:37.934504 30905 log.cc:1079] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/d40ea4b9f8f84dfbbef4203f5282d67b/wal-000000033 (ops 159-163)
I20260812 06:17:37.934536 30905 log.cc:1079] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/d40ea4b9f8f84dfbbef4203f5282d67b/wal-000000034 (ops 164-168)
I20260812 06:17:37.934568 30905 log.cc:1079] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/d40ea4b9f8f84dfbbef4203f5282d67b/wal-000000035 (ops 169-172)
I20260812 06:17:37.934590 30905 log.cc:1079] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/d40ea4b9f8f84dfbbef4203f5282d67b/wal-000000036 (ops 173-177)
I20260812 06:17:37.934623 30905 log.cc:1079] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/d40ea4b9f8f84dfbbef4203f5282d67b/wal-000000037 (ops 178-182)
I20260812 06:17:37.934648 30905 log.cc:1079] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/d40ea4b9f8f84dfbbef4203f5282d67b/wal-000000038 (ops 183-186)
I20260812 06:17:37.934679 30905 log.cc:1079] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/d40ea4b9f8f84dfbbef4203f5282d67b/wal-000000039 (ops 187-191)
I20260812 06:17:37.958760 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: LogGCOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.025s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:17:37.959246 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling UndoDeltaBlockGCOp(d40ea4b9f8f84dfbbef4203f5282d67b): 483 bytes on disk
I20260812 06:17:37.959784 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: UndoDeltaBlockGCOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4}
I20260812 06:17:37.960361 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=3.181125
I20260812 06:17:37.974946 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.014s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":3728,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:37.975363 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=2.188937
I20260812 06:17:37.990453 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.015s	user 0.012s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5582,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:37.990935 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling MajorDeltaCompactionOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=1.000000
I20260812 06:17:38.123106 30740 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.496s	user 1.642s	sys 0.161s
I20260812 06:17:38.193295 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: MajorDeltaCompactionOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.202s	user 0.123s	sys 0.078s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020732,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":252,"lbm_read_time_us":13819,"lbm_reads_lt_1ms":770,"lbm_write_time_us":37647,"lbm_writes_lt_1ms":743,"mutex_wait_us":3,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":95,"threads_started":1,"update_count":3500}
I20260812 06:17:38.193956 30999 maintenance_manager.cc:419] P 7625e313ba4741949f0904f58db35b5e: Scheduling FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b): perf score=10.126437
I20260812 06:17:38.202124 30740 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.078s	user 0.002s	sys 0.000s
I20260812 06:17:38.202682 30740 tablet_server.cc:179] TabletServer@127.30.5.1:0 shutting down...
I20260812 06:17:38.238523 30905 maintenance_manager.cc:643] P 7625e313ba4741949f0904f58db35b5e: FlushDeltaMemStoresOp(d40ea4b9f8f84dfbbef4203f5282d67b) complete. Timing: real 0.044s	user 0.013s	sys 0.028s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13772,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:38.239127 30740 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:38.239517 30740 tablet_replica.cc:333] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e: stopping tablet replica
I20260812 06:17:38.239708 30740 raft_consensus.cc:2243] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:38.239897 30740 raft_consensus.cc:2272] T d40ea4b9f8f84dfbbef4203f5282d67b P 7625e313ba4741949f0904f58db35b5e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:38.244266 30740 tablet_server.cc:196] TabletServer@127.30.5.1:0 shutdown complete.
I20260812 06:17:38.251242 30740 master.cc:562] Master@127.30.5.62:39283 shutting down...
I20260812 06:17:38.254839 30740 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 859ac024cced475283ab797a6550e147 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:38.254966 30740 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 859ac024cced475283ab797a6550e147 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:38.255016 30740 tablet_replica.cc:333] T 00000000000000000000000000000000 P 859ac024cced475283ab797a6550e147: stopping tablet replica
I20260812 06:17:38.266788 30740 master.cc:584] Master@127.30.5.62:39283 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (4947 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:38.338440 30740 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.30.5.62:39319
I20260812 06:17:38.338832 30740 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:38.340592 31062 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:38.340715 31063 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:38.340788 30740 server_base.cc:1061] running on GCE node
W20260812 06:17:38.340679 31069 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:38.341051 30740 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:38.341120 30740 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:38.341141 30740 hybrid_clock.cc:648] HybridClock initialized: now 1786515458341142 us; error 0 us; skew 500 ppm
I20260812 06:17:38.341965 30740 webserver.cc:533] Webserver started at http://127.30.5.62:39135/ using document root <none> and password file <none>
I20260812 06:17:38.342115 30740 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:38.342162 30740 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:38.342237 30740 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:38.342603 30740 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/master-0-root/instance:
uuid: "b3978fc5c0ef4030a73ed6e920beb446"
format_stamp: "Formatted at 2026-08-12 06:17:38 on dist-test-slave-266d"
I20260812 06:17:38.343978 30740 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:38.344794 31079 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:38.344985 30740 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:38.345050 30740 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/master-0-root
uuid: "b3978fc5c0ef4030a73ed6e920beb446"
format_stamp: "Formatted at 2026-08-12 06:17:38 on dist-test-slave-266d"
I20260812 06:17:38.345132 30740 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:38.354791 30740 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:38.355091 30740 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:38.359623 30740 rpc_server.cc:307] RPC server started. Bound to: 127.30.5.62:39319
I20260812 06:17:38.368645 31179 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.30.5.62:39319 every 8 connection(s)
I20260812 06:17:38.371778 31180 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:38.373669 31180 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b3978fc5c0ef4030a73ed6e920beb446: Bootstrap starting.
I20260812 06:17:38.374393 31180 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P b3978fc5c0ef4030a73ed6e920beb446: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:38.375330 31180 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b3978fc5c0ef4030a73ed6e920beb446: No bootstrap required, opened a new log
I20260812 06:17:38.375680 31180 raft_consensus.cc:359] T 00000000000000000000000000000000 P b3978fc5c0ef4030a73ed6e920beb446 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b3978fc5c0ef4030a73ed6e920beb446" member_type: VOTER }
I20260812 06:17:38.375761 31180 raft_consensus.cc:385] T 00000000000000000000000000000000 P b3978fc5c0ef4030a73ed6e920beb446 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:38.375790 31180 raft_consensus.cc:740] T 00000000000000000000000000000000 P b3978fc5c0ef4030a73ed6e920beb446 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b3978fc5c0ef4030a73ed6e920beb446, State: Initialized, Role: FOLLOWER
I20260812 06:17:38.375900 31180 consensus_queue.cc:260] T 00000000000000000000000000000000 P b3978fc5c0ef4030a73ed6e920beb446 [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: "b3978fc5c0ef4030a73ed6e920beb446" member_type: VOTER }
I20260812 06:17:38.375983 31180 raft_consensus.cc:399] T 00000000000000000000000000000000 P b3978fc5c0ef4030a73ed6e920beb446 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:38.376021 31180 raft_consensus.cc:493] T 00000000000000000000000000000000 P b3978fc5c0ef4030a73ed6e920beb446 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:38.376057 31180 raft_consensus.cc:3060] T 00000000000000000000000000000000 P b3978fc5c0ef4030a73ed6e920beb446 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:38.376696 31180 raft_consensus.cc:515] T 00000000000000000000000000000000 P b3978fc5c0ef4030a73ed6e920beb446 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b3978fc5c0ef4030a73ed6e920beb446" member_type: VOTER }
I20260812 06:17:38.376808 31180 leader_election.cc:304] T 00000000000000000000000000000000 P b3978fc5c0ef4030a73ed6e920beb446 [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: b3978fc5c0ef4030a73ed6e920beb446; no voters: 
I20260812 06:17:38.376945 31180 leader_election.cc:290] T 00000000000000000000000000000000 P b3978fc5c0ef4030a73ed6e920beb446 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:38.377063 31186 raft_consensus.cc:2804] T 00000000000000000000000000000000 P b3978fc5c0ef4030a73ed6e920beb446 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:38.377288 31186 raft_consensus.cc:697] T 00000000000000000000000000000000 P b3978fc5c0ef4030a73ed6e920beb446 [term 1 LEADER]: Becoming Leader. State: Replica: b3978fc5c0ef4030a73ed6e920beb446, State: Running, Role: LEADER
I20260812 06:17:38.377388 31180 sys_catalog.cc:565] T 00000000000000000000000000000000 P b3978fc5c0ef4030a73ed6e920beb446 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:38.377435 31186 consensus_queue.cc:237] T 00000000000000000000000000000000 P b3978fc5c0ef4030a73ed6e920beb446 [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: "b3978fc5c0ef4030a73ed6e920beb446" member_type: VOTER }
I20260812 06:17:38.377880 31187 sys_catalog.cc:455] T 00000000000000000000000000000000 P b3978fc5c0ef4030a73ed6e920beb446 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "b3978fc5c0ef4030a73ed6e920beb446" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b3978fc5c0ef4030a73ed6e920beb446" member_type: VOTER } }
I20260812 06:17:38.377892 31188 sys_catalog.cc:455] T 00000000000000000000000000000000 P b3978fc5c0ef4030a73ed6e920beb446 [sys.catalog]: SysCatalogTable state changed. Reason: New leader b3978fc5c0ef4030a73ed6e920beb446. Latest consensus state: current_term: 1 leader_uuid: "b3978fc5c0ef4030a73ed6e920beb446" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b3978fc5c0ef4030a73ed6e920beb446" member_type: VOTER } }
I20260812 06:17:38.377995 31188 sys_catalog.cc:458] T 00000000000000000000000000000000 P b3978fc5c0ef4030a73ed6e920beb446 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:38.378214 31187 sys_catalog.cc:458] T 00000000000000000000000000000000 P b3978fc5c0ef4030a73ed6e920beb446 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:38.378270 31196 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:38.379257 31196 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:38.379412 30740 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:38.380951 31196 catalog_manager.cc:1383] Generated new cluster ID: 3eb7b77fb02545428f65f48378104d10
I20260812 06:17:38.381006 31196 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:38.391618 31196 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:38.392133 31196 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:38.398797 31196 catalog_manager.cc:6092] T 00000000000000000000000000000000 P b3978fc5c0ef4030a73ed6e920beb446: Generated new TSK 0
I20260812 06:17:38.398949 31196 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:38.411499 30740 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:38.413249 31217 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:38.413251 31229 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:38.413316 30740 server_base.cc:1061] running on GCE node
W20260812 06:17:38.413333 31219 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:38.413671 30740 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:38.413712 30740 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:38.413726 30740 hybrid_clock.cc:648] HybridClock initialized: now 1786515458413726 us; error 0 us; skew 500 ppm
I20260812 06:17:38.414515 30740 webserver.cc:533] Webserver started at http://127.30.5.1:43163/ using document root <none> and password file <none>
I20260812 06:17:38.414637 30740 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:38.414678 30740 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:38.414729 30740 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:38.415053 30740 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/instance:
uuid: "b11fc78e5d694a2fad340e001d690802"
format_stamp: "Formatted at 2026-08-12 06:17:38 on dist-test-slave-266d"
I20260812 06:17:38.416389 30740 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:38.417239 31236 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:38.417454 30740 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:38.417515 30740 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root
uuid: "b11fc78e5d694a2fad340e001d690802"
format_stamp: "Formatted at 2026-08-12 06:17:38 on dist-test-slave-266d"
I20260812 06:17:38.417578 30740 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-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:38.431196 30740 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:38.431486 30740 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:38.431737 30740 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:38.432156 30740 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:38.432191 30740 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:38.432224 30740 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:38.432250 30740 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:38.436079 30740 rpc_server.cc:307] RPC server started. Bound to: 127.30.5.1:38307
I20260812 06:17:38.436106 31350 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.30.5.1:38307 every 8 connection(s)
I20260812 06:17:38.443262 31351 heartbeater.cc:344] Connected to a master server at 127.30.5.62:39319
I20260812 06:17:38.443351 31351 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:38.443545 31351 heartbeater.cc:507] Master 127.30.5.62:39319 requested a full tablet report, sending...
I20260812 06:17:38.444125 31121 ts_manager.cc:194] Registered new tserver with Master: b11fc78e5d694a2fad340e001d690802 (127.30.5.1:38307)
I20260812 06:17:38.444172 30740 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.007693481s
I20260812 06:17:38.445079 31121 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:55412
I20260812 06:17:38.450798 31121 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:55420:
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:38.458673 31291 tablet_service.cc:1511] Processing CreateTablet for tablet 1daaaf05cd4c46fe8b65bd6b9b4ea94c (DEFAULT_TABLE table=heavy-update-compaction-test [id=396823cb1d1d448c935c302afb696989]), partition=
I20260812 06:17:38.458925 31291 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 1daaaf05cd4c46fe8b65bd6b9b4ea94c. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:38.460722 31373 tablet_bootstrap.cc:492] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Bootstrap starting.
I20260812 06:17:38.461671 31373 tablet_bootstrap.cc:654] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:38.462634 31373 tablet_bootstrap.cc:492] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: No bootstrap required, opened a new log
I20260812 06:17:38.462706 31373 ts_tablet_manager.cc:1403] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:17:38.463083 31373 raft_consensus.cc:359] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b11fc78e5d694a2fad340e001d690802" member_type: VOTER last_known_addr { host: "127.30.5.1" port: 38307 } }
I20260812 06:17:38.463164 31373 raft_consensus.cc:385] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:38.463195 31373 raft_consensus.cc:740] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b11fc78e5d694a2fad340e001d690802, State: Initialized, Role: FOLLOWER
I20260812 06:17:38.463321 31373 consensus_queue.cc:260] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802 [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: "b11fc78e5d694a2fad340e001d690802" member_type: VOTER last_known_addr { host: "127.30.5.1" port: 38307 } }
I20260812 06:17:38.463390 31373 raft_consensus.cc:399] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:38.463424 31373 raft_consensus.cc:493] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:38.463474 31373 raft_consensus.cc:3060] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:38.464226 31373 raft_consensus.cc:515] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b11fc78e5d694a2fad340e001d690802" member_type: VOTER last_known_addr { host: "127.30.5.1" port: 38307 } }
I20260812 06:17:38.464365 31373 leader_election.cc:304] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802 [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: b11fc78e5d694a2fad340e001d690802; no voters: 
I20260812 06:17:38.464555 31373 leader_election.cc:290] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:38.464644 31377 raft_consensus.cc:2804] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:38.464843 31377 raft_consensus.cc:697] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802 [term 1 LEADER]: Becoming Leader. State: Replica: b11fc78e5d694a2fad340e001d690802, State: Running, Role: LEADER
I20260812 06:17:38.464867 31373 ts_tablet_manager.cc:1434] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:38.464876 31351 heartbeater.cc:499] Master 127.30.5.62:39319 was elected leader, sending a full tablet report...
I20260812 06:17:38.464979 31377 consensus_queue.cc:237] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802 [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: "b11fc78e5d694a2fad340e001d690802" member_type: VOTER last_known_addr { host: "127.30.5.1" port: 38307 } }
I20260812 06:17:38.466190 31121 catalog_manager.cc:5719] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802 reported cstate change: term changed from 0 to 1, leader changed from <none> to b11fc78e5d694a2fad340e001d690802 (127.30.5.1). New cstate: current_term: 1 leader_uuid: "b11fc78e5d694a2fad340e001d690802" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b11fc78e5d694a2fad340e001d690802" member_type: VOTER last_known_addr { host: "127.30.5.1" port: 38307 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:38.516878 30740 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.047s	user 0.016s	sys 0.005s
I20260812 06:17:38.686910 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushMRSOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=23.023690
I20260812 06:17:38.848368 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushMRSOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.161s	user 0.120s	sys 0.036s Metrics: {"bytes_written":13538208,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":208,"dirs.run_wall_time_us":1016,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41710,"lbm_writes_lt_1ms":887,"mutex_wait_us":1602,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":2432,"update_count":1650}
I20260812 06:17:38.848995 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling LogGCOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): free 20743880 bytes of WAL
I20260812 06:17:38.849222 31245 log_reader.cc:385] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c: removed 2 log segments from log reader
I20260812 06:17:38.849270 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000001 (ops 1-6)
I20260812 06:17:38.849306 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000002 (ops 7-11)
I20260812 06:17:38.852958 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: LogGCOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.004s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:38.853282 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=2.188937
I20260812 06:17:38.863131 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3856513,"delete_count":0,"lbm_write_time_us":3420,"lbm_writes_lt_1ms":97,"reinsert_count":0,"update_count":470}
I20260812 06:17:38.863520 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling UndoDeltaBlockGCOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): 20513814 bytes on disk
I20260812 06:17:38.863946 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: UndoDeltaBlockGCOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:17:38.864360 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=1.196750
I20260812 06:17:38.875890 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3118055,"delete_count":0,"lbm_write_time_us":4108,"lbm_writes_lt_1ms":79,"reinsert_count":0,"update_count":380}
I20260812 06:17:38.876396 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling MajorDeltaCompactionOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=1.000000
I20260812 06:17:39.023125 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: MajorDeltaCompactionOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.147s	user 0.126s	sys 0.020s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815771,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":749,"lbm_read_time_us":11025,"lbm_reads_lt_1ms":569,"lbm_write_time_us":25666,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2944,"thread_start_us":308,"threads_started":5,"update_count":2500}
I20260812 06:17:39.023680 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=14.095187
I20260812 06:17:39.075110 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.051s	user 0.036s	sys 0.011s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21469,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:39.075572 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=2.188937
I20260812 06:17:39.085322 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3595,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:39.085856 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling MajorDeltaCompactionOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=1.000000
I20260812 06:17:39.246304 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: MajorDeltaCompactionOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.160s	user 0.121s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":124,"lbm_read_time_us":9583,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27451,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13696,"update_count":2500}
I20260812 06:17:39.246887 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=14.095187
I20260812 06:17:39.299361 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.052s	user 0.033s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21576,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:39.299944 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling MajorDeltaCompactionOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=1.000000
I20260812 06:17:39.440786 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: MajorDeltaCompactionOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.141s	user 0.092s	sys 0.042s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713154,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":3217,"lbm_read_time_us":8690,"lbm_reads_lt_1ms":463,"lbm_write_time_us":22349,"lbm_writes_lt_1ms":443,"mutex_wait_us":2514,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2000}
I20260812 06:17:39.441288 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=14.095187
I20260812 06:17:39.488253 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.047s	user 0.030s	sys 0.014s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20631,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:39.488785 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=2.188937
I20260812 06:17:39.499346 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3611,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:39.499948 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling MajorDeltaCompactionOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=1.000000
I20260812 06:17:39.697304 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: MajorDeltaCompactionOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.197s	user 0.113s	sys 0.069s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1011,"dirs.run_cpu_time_us":497,"dirs.run_wall_time_us":3673,"lbm_read_time_us":11939,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29703,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:39.698433 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=15.087375
I20260812 06:17:39.744953 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.046s	user 0.026s	sys 0.016s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":19914,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:39.745505 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=2.188937
I20260812 06:17:39.762782 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.017s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4690,"lbm_writes_lt_1ms":93,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":450}
I20260812 06:17:39.763278 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=2.188937
I20260812 06:17:39.787997 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.025s	user 0.010s	sys 0.011s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4985,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:39.788549 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling MajorDeltaCompactionOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=1.000000
I20260812 06:17:39.990319 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: MajorDeltaCompactionOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.202s	user 0.141s	sys 0.060s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918201,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":143,"lbm_read_time_us":14317,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32463,"lbm_writes_lt_1ms":643,"mutex_wait_us":22,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10112,"update_count":3000}
I20260812 06:17:39.990865 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=15.087375
I20260812 06:17:40.043627 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.053s	user 0.025s	sys 0.024s Metrics: {"bytes_written":16820145,"delete_count":0,"lbm_write_time_us":17790,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:40.044206 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=3.181125
I20260812 06:17:40.055814 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4594950,"delete_count":0,"lbm_write_time_us":4144,"lbm_writes_lt_1ms":115,"reinsert_count":0,"update_count":560}
I20260812 06:17:40.056252 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=2.188937
I20260812 06:17:40.067588 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3200105,"delete_count":0,"lbm_write_time_us":4173,"lbm_writes_lt_1ms":81,"reinsert_count":0,"update_count":390}
I20260812 06:17:40.067979 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushMRSOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=1.000000
I20260812 06:17:40.103520 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushMRSOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.035s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":49,"dirs.run_cpu_time_us":155,"dirs.run_wall_time_us":1222,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1869,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:40.104115 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling LogGCOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): free 129320499 bytes of WAL
I20260812 06:17:40.104336 31245 log_reader.cc:385] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c: removed 13 log segments from log reader
I20260812 06:17:40.104383 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000003 (ops 12-16)
I20260812 06:17:40.104410 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000004 (ops 17-21)
I20260812 06:17:40.104429 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000005 (ops 22-26)
I20260812 06:17:40.104460 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000006 (ops 27-31)
I20260812 06:17:40.104489 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000007 (ops 32-36)
I20260812 06:17:40.104523 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000008 (ops 37-40)
I20260812 06:17:40.104555 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000009 (ops 41-45)
I20260812 06:17:40.104588 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000010 (ops 46-50)
I20260812 06:17:40.104620 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000011 (ops 51-54)
I20260812 06:17:40.104652 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000012 (ops 55-59)
I20260812 06:17:40.104684 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000013 (ops 60-64)
I20260812 06:17:40.104717 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000014 (ops 65-69)
I20260812 06:17:40.104749 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000015 (ops 70-74)
I20260812 06:17:40.126044 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: LogGCOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.022s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:17:40.126535 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling UndoDeltaBlockGCOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): 481 bytes on disk
I20260812 06:17:40.126981 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: UndoDeltaBlockGCOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) 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:40.127521 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=2.188937
I20260812 06:17:40.151501 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.024s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5479,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:40.151961 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=2.188937
I20260812 06:17:40.161448 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.009s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3521,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:40.161927 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling MajorDeltaCompactionOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=1.000000
I20260812 06:17:40.380481 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: MajorDeltaCompactionOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.218s	user 0.138s	sys 0.080s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37123257,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":80,"lbm_read_time_us":17122,"lbm_reads_lt_1ms":875,"lbm_write_time_us":36095,"lbm_writes_lt_1ms":843,"mutex_wait_us":25,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":13824,"thread_start_us":76,"threads_started":1,"update_count":4000}
I20260812 06:17:40.381008 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=18.063937
I20260812 06:17:40.434940 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.053s	user 0.039s	sys 0.012s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":23429,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:40.435401 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=2.188937
I20260812 06:17:40.458467 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.023s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4084,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:40.458874 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=2.188937
I20260812 06:17:40.468281 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3695,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:40.468657 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling MajorDeltaCompactionOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=1.000000
I20260812 06:17:40.675900 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: MajorDeltaCompactionOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.207s	user 0.151s	sys 0.056s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":33020630,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":616,"lbm_read_time_us":14906,"lbm_reads_lt_1ms":773,"lbm_write_time_us":44262,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":3500}
I20260812 06:17:40.676561 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=14.095187
I20260812 06:17:40.761318 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.084s	user 0.027s	sys 0.010s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":62834,"lbm_writes_1-10_ms":1,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":401,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2000}
I20260812 06:17:40.762327 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=2.188937
I20260812 06:17:40.772495 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3845,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":500}
I20260812 06:17:40.772974 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling MajorDeltaCompactionOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=1.000000
I20260812 06:17:40.917870 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: MajorDeltaCompactionOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.145s	user 0.109s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":223,"lbm_read_time_us":10222,"lbm_reads_lt_1ms":564,"lbm_write_time_us":24495,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2500}
I20260812 06:17:40.918565 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=14.095187
I20260812 06:17:40.963436 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.045s	user 0.010s	sys 0.029s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":17482,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:40.963940 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling MajorDeltaCompactionOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=1.000000
I20260812 06:17:41.113683 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: MajorDeltaCompactionOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.150s	user 0.101s	sys 0.040s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713149,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":591,"lbm_read_time_us":10098,"lbm_reads_lt_1ms":463,"lbm_write_time_us":22184,"lbm_writes_lt_1ms":443,"mutex_wait_us":67,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:17:41.114241 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=14.095187
I20260812 06:17:41.159355 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.045s	user 0.019s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18132,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:41.159930 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=2.188937
I20260812 06:17:41.169600 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.009s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3601,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:41.170912 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling MajorDeltaCompactionOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=1.000000
I20260812 06:17:41.350450 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: MajorDeltaCompactionOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.179s	user 0.112s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1044,"lbm_read_time_us":9410,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30193,"lbm_writes_lt_1ms":543,"mutex_wait_us":276,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4736,"update_count":2500}
I20260812 06:17:41.350927 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=14.095187
I20260812 06:17:41.400238 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.049s	user 0.025s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20821,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:41.400735 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=2.188937
I20260812 06:17:41.411299 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3752,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:41.411736 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushMRSOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=1.000000
I20260812 06:17:41.436625 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushMRSOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.025s	user 0.021s	sys 0.001s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":233,"dirs.run_wall_time_us":1276,"drs_written":1,"lbm_read_time_us":35,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1323,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:41.437286 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling LogGCOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): free 120100343 bytes of WAL
I20260812 06:17:41.437513 31245 log_reader.cc:385] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c: removed 12 log segments from log reader
I20260812 06:17:41.437584 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000016 (ops 75-78)
I20260812 06:17:41.437628 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000017 (ops 79-83)
I20260812 06:17:41.437662 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000018 (ops 84-88)
I20260812 06:17:41.437695 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000019 (ops 89-92)
I20260812 06:17:41.437722 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000020 (ops 93-97)
I20260812 06:17:41.437750 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000021 (ops 98-102)
I20260812 06:17:41.437779 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000022 (ops 103-106)
I20260812 06:17:41.437810 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000023 (ops 107-111)
I20260812 06:17:41.437842 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000024 (ops 112-116)
I20260812 06:17:41.437870 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000025 (ops 117-121)
I20260812 06:17:41.437897 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000026 (ops 122-126)
I20260812 06:17:41.437925 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000027 (ops 127-131)
I20260812 06:17:41.462260 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: LogGCOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.025s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:17:41.463584 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=2.188937
I20260812 06:17:41.489971 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.026s	user 0.003s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4971,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:41.490407 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling UndoDeltaBlockGCOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): 447 bytes on disk
I20260812 06:17:41.490828 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: UndoDeltaBlockGCOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4}
I20260812 06:17:41.491343 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=2.188937
I20260812 06:17:41.500882 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.009s	user 0.003s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3630,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:41.501302 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling MajorDeltaCompactionOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=1.000000
I20260812 06:17:41.725075 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: MajorDeltaCompactionOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.224s	user 0.132s	sys 0.090s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020746,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":255,"lbm_read_time_us":14854,"lbm_reads_lt_1ms":774,"lbm_write_time_us":36747,"lbm_writes_lt_1ms":743,"mutex_wait_us":41,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":10624,"thread_start_us":77,"threads_started":1,"update_count":3500}
I20260812 06:17:41.725656 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=18.063937
I20260812 06:17:41.787986 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.062s	user 0.038s	sys 0.015s Metrics: {"bytes_written":20512313,"delete_count":0,"lbm_write_time_us":24691,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:41.788483 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=2.188937
I20260812 06:17:41.804200 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6072,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:41.804679 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling MajorDeltaCompactionOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=1.000000
I20260812 06:17:42.007157 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: MajorDeltaCompactionOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.202s	user 0.124s	sys 0.066s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918095,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":254,"lbm_read_time_us":13501,"lbm_reads_lt_1ms":672,"lbm_write_time_us":32205,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":3000}
I20260812 06:17:42.007687 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=18.063937
I20260812 06:17:42.070704 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.063s	user 0.039s	sys 0.012s Metrics: {"bytes_written":20512345,"delete_count":0,"lbm_write_time_us":23425,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:42.071228 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=2.188937
I20260812 06:17:42.087006 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6043,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:42.087574 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling MajorDeltaCompactionOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=1.000000
I20260812 06:17:42.272599 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: MajorDeltaCompactionOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.185s	user 0.129s	sys 0.056s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918127,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":539,"lbm_read_time_us":13079,"lbm_reads_lt_1ms":672,"lbm_write_time_us":32692,"lbm_writes_lt_1ms":643,"mutex_wait_us":319,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":22784,"update_count":3000}
I20260812 06:17:42.273275 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=16.079562
I20260812 06:17:42.345230 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.072s	user 0.032s	sys 0.024s Metrics: {"bytes_written":17968820,"delete_count":0,"lbm_write_time_us":26204,"lbm_writes_lt_1ms":441,"reinsert_count":0,"update_count":2190}
I20260812 06:17:42.345690 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=5.165500
I20260812 06:17:42.362172 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.016s	user 0.015s	sys 0.001s Metrics: {"bytes_written":6646165,"delete_count":0,"lbm_write_time_us":6429,"lbm_writes_lt_1ms":165,"reinsert_count":0,"update_count":810}
I20260812 06:17:42.362612 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling MajorDeltaCompactionOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=1.000000
I20260812 06:17:42.550813 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: MajorDeltaCompactionOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.188s	user 0.112s	sys 0.071s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1264,"lbm_read_time_us":13792,"lbm_reads_lt_1ms":672,"lbm_write_time_us":29717,"lbm_writes_lt_1ms":643,"mutex_wait_us":419,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":3000}
I20260812 06:17:42.552238 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=17.071750
I20260812 06:17:42.595806 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.043s	user 0.020s	sys 0.019s Metrics: {"bytes_written":18666230,"delete_count":0,"lbm_write_time_us":18537,"lbm_writes_lt_1ms":458,"reinsert_count":0,"update_count":2275}
I20260812 06:17:42.596366 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=1.196750
I20260812 06:17:42.607787 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.011s	user 0.007s	sys 0.000s Metrics: {"bytes_written":2256533,"delete_count":0,"lbm_write_time_us":2904,"lbm_writes_lt_1ms":58,"reinsert_count":0,"update_count":275}
I20260812 06:17:42.608228 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=2.188937
I20260812 06:17:42.621306 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.013s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5118,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:42.621727 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling MajorDeltaCompactionOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=1.000000
I20260812 06:17:42.823623 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: MajorDeltaCompactionOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.202s	user 0.126s	sys 0.076s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918163,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":320,"lbm_read_time_us":14039,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34211,"lbm_writes_lt_1ms":643,"mutex_wait_us":78,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":3000}
I20260812 06:17:42.824328 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=14.095187
I20260812 06:17:42.873210 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.049s	user 0.028s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19296,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:42.873907 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=3.181125
I20260812 06:17:42.892966 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.019s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4430855,"delete_count":0,"lbm_write_time_us":4639,"lbm_writes_lt_1ms":111,"reinsert_count":0,"update_count":540}
I20260812 06:17:42.893477 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=2.188937
I20260812 06:17:42.902354 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.009s	user 0.001s	sys 0.006s Metrics: {"bytes_written":3774459,"delete_count":0,"lbm_write_time_us":3277,"lbm_writes_lt_1ms":95,"reinsert_count":0,"update_count":460}
I20260812 06:17:42.902844 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushMRSOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=1.000000
I20260812 06:17:42.932255 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushMRSOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.029s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":215,"dirs.run_wall_time_us":1280,"drs_written":1,"lbm_read_time_us":34,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1568,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:42.932947 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling LogGCOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): free 133024609 bytes of WAL
I20260812 06:17:42.933195 31245 log_reader.cc:385] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c: removed 13 log segments from log reader
I20260812 06:17:42.933245 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000028 (ops 132-136)
I20260812 06:17:42.933275 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000029 (ops 137-141)
I20260812 06:17:42.933315 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000030 (ops 142-146)
I20260812 06:17:42.933349 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000031 (ops 147-150)
I20260812 06:17:42.933379 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000032 (ops 151-155)
I20260812 06:17:42.933411 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000033 (ops 156-160)
I20260812 06:17:42.933441 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000034 (ops 161-165)
I20260812 06:17:42.933473 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000035 (ops 166-171)
I20260812 06:17:42.933504 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000036 (ops 172-176)
I20260812 06:17:42.933534 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000037 (ops 177-180)
I20260812 06:17:42.933565 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000038 (ops 181-185)
I20260812 06:17:42.933596 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000039 (ops 186-190)
I20260812 06:17:42.933627 31245 log.cc:1079] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: Deleting log segment in path: /tmp/dist-test-task8565XG/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453380950-30740-0/minicluster-data/ts-0-root/wals/1daaaf05cd4c46fe8b65bd6b9b4ea94c/wal-000000040 (ops 191-195)
I20260812 06:17:42.957969 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: LogGCOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.025s	user 0.002s	sys 0.022s Metrics: {}
I20260812 06:17:42.958369 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling UndoDeltaBlockGCOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): 492 bytes on disk
I20260812 06:17:42.958827 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: UndoDeltaBlockGCOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:17:42.959364 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=3.181125
I20260812 06:17:42.976008 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6626,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:42.976384 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=2.188937
I20260812 06:17:42.985450 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: FlushDeltaMemStoresOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3359,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:42.985874 31355 maintenance_manager.cc:419] P b11fc78e5d694a2fad340e001d690802: Scheduling MajorDeltaCompactionOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c): perf score=1.000000
I20260812 06:17:43.068974 30740 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.552s	user 1.639s	sys 0.160s
I20260812 06:17:43.177012 30740 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.108s	user 0.001s	sys 0.000s
I20260812 06:17:43.177536 30740 tablet_server.cc:179] TabletServer@127.30.5.1:0 shutting down...
I20260812 06:17:43.217978 31245 maintenance_manager.cc:643] P b11fc78e5d694a2fad340e001d690802: MajorDeltaCompactionOp(1daaaf05cd4c46fe8b65bd6b9b4ea94c) complete. Timing: real 0.232s	user 0.125s	sys 0.105s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37123263,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":1409,"lbm_read_time_us":15909,"lbm_reads_lt_1ms":871,"lbm_write_time_us":40675,"lbm_writes_lt_1ms":843,"mutex_wait_us":316,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":81,"threads_started":1,"update_count":4000}
I20260812 06:17:43.218977 30740 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:43.219208 30740 tablet_replica.cc:333] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802: stopping tablet replica
I20260812 06:17:43.219331 30740 raft_consensus.cc:2243] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:43.219487 30740 raft_consensus.cc:2272] T 1daaaf05cd4c46fe8b65bd6b9b4ea94c P b11fc78e5d694a2fad340e001d690802 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:43.223888 30740 tablet_server.cc:196] TabletServer@127.30.5.1:0 shutdown complete.
I20260812 06:17:43.288540 30740 master.cc:562] Master@127.30.5.62:39319 shutting down...
I20260812 06:17:43.291577 30740 raft_consensus.cc:2243] T 00000000000000000000000000000000 P b3978fc5c0ef4030a73ed6e920beb446 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:43.291752 30740 raft_consensus.cc:2272] T 00000000000000000000000000000000 P b3978fc5c0ef4030a73ed6e920beb446 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:43.291829 30740 tablet_replica.cc:333] T 00000000000000000000000000000000 P b3978fc5c0ef4030a73ed6e920beb446: stopping tablet replica
I20260812 06:17:43.304061 30740 master.cc:584] Master@127.30.5.62:39319 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5033 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (9982 ms total)

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