[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:20:25.065727 28348 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.27.175.62:44297
I20260812 06:20:25.066795 28348 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:20:25.067438 28348 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:20:25.074076 28348 server_base.cc:1061] running on GCE node
W20260812 06:20:25.074221 28354 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:25.074360 28359 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:25.074498 28356 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:25.074975 28348 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:25.075111 28348 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:25.075171 28348 hybrid_clock.cc:648] HybridClock initialized: now 1786515625075167 us; error 0 us; skew 500 ppm
I20260812 06:20:25.077095 28348 webserver.cc:533] Webserver started at http://127.27.175.62:37289/ using document root <none> and password file <none>
I20260812 06:20:25.077761 28348 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:25.077858 28348 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:25.078099 28348 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:25.079823 28348 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/master-0-root/instance:
uuid: "9f121159b6b3459db8ce375a593bca74"
format_stamp: "Formatted at 2026-08-12 06:20:25 on dist-test-slave-tm1g"
I20260812 06:20:25.083346 28348 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:20:25.085539 28366 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:25.086666 28348 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:20:25.086807 28348 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/master-0-root
uuid: "9f121159b6b3459db8ce375a593bca74"
format_stamp: "Formatted at 2026-08-12 06:20:25 on dist-test-slave-tm1g"
I20260812 06:20:25.086917 28348 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:25.109297 28348 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:25.110167 28348 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:20:25.110457 28348 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:25.119891 28348 rpc_server.cc:307] RPC server started. Bound to: 127.27.175.62:44297
I20260812 06:20:25.119891 28431 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.175.62:44297 every 8 connection(s)
I20260812 06:20:25.122486 28432 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:25.128454 28432 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 9f121159b6b3459db8ce375a593bca74: Bootstrap starting.
I20260812 06:20:25.131039 28432 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 9f121159b6b3459db8ce375a593bca74: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:25.132009 28432 log.cc:826] T 00000000000000000000000000000000 P 9f121159b6b3459db8ce375a593bca74: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:25.133780 28432 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 9f121159b6b3459db8ce375a593bca74: No bootstrap required, opened a new log
I20260812 06:20:25.136679 28432 raft_consensus.cc:359] T 00000000000000000000000000000000 P 9f121159b6b3459db8ce375a593bca74 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9f121159b6b3459db8ce375a593bca74" member_type: VOTER }
I20260812 06:20:25.136899 28432 raft_consensus.cc:385] T 00000000000000000000000000000000 P 9f121159b6b3459db8ce375a593bca74 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:25.136996 28432 raft_consensus.cc:740] T 00000000000000000000000000000000 P 9f121159b6b3459db8ce375a593bca74 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 9f121159b6b3459db8ce375a593bca74, State: Initialized, Role: FOLLOWER
I20260812 06:20:25.137660 28432 consensus_queue.cc:260] T 00000000000000000000000000000000 P 9f121159b6b3459db8ce375a593bca74 [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: "9f121159b6b3459db8ce375a593bca74" member_type: VOTER }
I20260812 06:20:25.137840 28432 raft_consensus.cc:399] T 00000000000000000000000000000000 P 9f121159b6b3459db8ce375a593bca74 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:25.137926 28432 raft_consensus.cc:493] T 00000000000000000000000000000000 P 9f121159b6b3459db8ce375a593bca74 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:25.138055 28432 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 9f121159b6b3459db8ce375a593bca74 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:25.138953 28432 raft_consensus.cc:515] T 00000000000000000000000000000000 P 9f121159b6b3459db8ce375a593bca74 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9f121159b6b3459db8ce375a593bca74" member_type: VOTER }
I20260812 06:20:25.139413 28432 leader_election.cc:304] T 00000000000000000000000000000000 P 9f121159b6b3459db8ce375a593bca74 [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: 9f121159b6b3459db8ce375a593bca74; no voters: 
I20260812 06:20:25.139765 28432 leader_election.cc:290] T 00000000000000000000000000000000 P 9f121159b6b3459db8ce375a593bca74 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:25.140044 28437 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 9f121159b6b3459db8ce375a593bca74 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:25.140353 28437 raft_consensus.cc:697] T 00000000000000000000000000000000 P 9f121159b6b3459db8ce375a593bca74 [term 1 LEADER]: Becoming Leader. State: Replica: 9f121159b6b3459db8ce375a593bca74, State: Running, Role: LEADER
I20260812 06:20:25.140740 28437 consensus_queue.cc:237] T 00000000000000000000000000000000 P 9f121159b6b3459db8ce375a593bca74 [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: "9f121159b6b3459db8ce375a593bca74" member_type: VOTER }
I20260812 06:20:25.140812 28432 sys_catalog.cc:565] T 00000000000000000000000000000000 P 9f121159b6b3459db8ce375a593bca74 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:25.142752 28439 sys_catalog.cc:455] T 00000000000000000000000000000000 P 9f121159b6b3459db8ce375a593bca74 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 9f121159b6b3459db8ce375a593bca74. Latest consensus state: current_term: 1 leader_uuid: "9f121159b6b3459db8ce375a593bca74" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9f121159b6b3459db8ce375a593bca74" member_type: VOTER } }
I20260812 06:20:25.142791 28438 sys_catalog.cc:455] T 00000000000000000000000000000000 P 9f121159b6b3459db8ce375a593bca74 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "9f121159b6b3459db8ce375a593bca74" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9f121159b6b3459db8ce375a593bca74" member_type: VOTER } }
I20260812 06:20:25.142879 28439 sys_catalog.cc:458] T 00000000000000000000000000000000 P 9f121159b6b3459db8ce375a593bca74 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:25.142899 28438 sys_catalog.cc:458] T 00000000000000000000000000000000 P 9f121159b6b3459db8ce375a593bca74 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:25.143250 28451 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:25.143363 28348 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:25.145608 28451 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:25.150753 28451 catalog_manager.cc:1383] Generated new cluster ID: fb1e1410bff340f1b3bd88b441d50cff
I20260812 06:20:25.150825 28451 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:25.178747 28451 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:25.179893 28451 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:25.188144 28451 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 9f121159b6b3459db8ce375a593bca74: Generated new TSK 0
I20260812 06:20:25.188892 28451 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:25.208467 28348 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:25.211647 28458 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:25.211736 28459 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:20:25.211748 28461 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:25.212110 28348 server_base.cc:1061] running on GCE node
I20260812 06:20:25.212280 28348 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:25.212325 28348 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:25.212347 28348 hybrid_clock.cc:648] HybridClock initialized: now 1786515625212347 us; error 0 us; skew 500 ppm
I20260812 06:20:25.213289 28348 webserver.cc:533] Webserver started at http://127.27.175.1:38279/ using document root <none> and password file <none>
I20260812 06:20:25.213456 28348 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:25.213512 28348 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:25.213579 28348 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:25.214002 28348 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/instance:
uuid: "6d018000d09e463baf600fffdfa68d6b"
format_stamp: "Formatted at 2026-08-12 06:20:25 on dist-test-slave-tm1g"
I20260812 06:20:25.215832 28348 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.001s	sys 0.002s
I20260812 06:20:25.216969 28466 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:25.217250 28348 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:25.217324 28348 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root
uuid: "6d018000d09e463baf600fffdfa68d6b"
format_stamp: "Formatted at 2026-08-12 06:20:25 on dist-test-slave-tm1g"
I20260812 06:20:25.217448 28348 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:25.254900 28348 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:25.255375 28348 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:25.255908 28348 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:25.256745 28348 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:25.256798 28348 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:25.256871 28348 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:25.256910 28348 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:25.263837 28348 rpc_server.cc:307] RPC server started. Bound to: 127.27.175.1:43589
I20260812 06:20:25.263877 28543 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.175.1:43589 every 8 connection(s)
I20260812 06:20:25.274549 28544 heartbeater.cc:344] Connected to a master server at 127.27.175.62:44297
I20260812 06:20:25.274809 28544 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:25.275332 28544 heartbeater.cc:507] Master 127.27.175.62:44297 requested a full tablet report, sending...
I20260812 06:20:25.277020 28387 ts_manager.cc:194] Registered new tserver with Master: 6d018000d09e463baf600fffdfa68d6b (127.27.175.1:43589)
I20260812 06:20:25.277122 28348 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012633577s
I20260812 06:20:25.278646 28387 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:60784
I20260812 06:20:25.287858 28387 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:60796:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:25.302838 28500 tablet_service.cc:1511] Processing CreateTablet for tablet 6c70aedd05f34a1daeda281595161051 (DEFAULT_TABLE table=heavy-update-compaction-test [id=940fa0463c3548dd9aa48ef1ad4eb598]), partition=
I20260812 06:20:25.303347 28500 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 6c70aedd05f34a1daeda281595161051. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:25.305738 28558 tablet_bootstrap.cc:492] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Bootstrap starting.
I20260812 06:20:25.306849 28558 tablet_bootstrap.cc:654] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:25.308117 28558 tablet_bootstrap.cc:492] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: No bootstrap required, opened a new log
I20260812 06:20:25.308213 28558 ts_tablet_manager.cc:1403] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:20:25.308771 28558 raft_consensus.cc:359] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6d018000d09e463baf600fffdfa68d6b" member_type: VOTER last_known_addr { host: "127.27.175.1" port: 43589 } }
I20260812 06:20:25.308899 28558 raft_consensus.cc:385] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:25.308936 28558 raft_consensus.cc:740] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6d018000d09e463baf600fffdfa68d6b, State: Initialized, Role: FOLLOWER
I20260812 06:20:25.309116 28558 consensus_queue.cc:260] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b [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: "6d018000d09e463baf600fffdfa68d6b" member_type: VOTER last_known_addr { host: "127.27.175.1" port: 43589 } }
I20260812 06:20:25.309223 28558 raft_consensus.cc:399] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:25.309259 28558 raft_consensus.cc:493] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:25.309307 28558 raft_consensus.cc:3060] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:25.310225 28558 raft_consensus.cc:515] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6d018000d09e463baf600fffdfa68d6b" member_type: VOTER last_known_addr { host: "127.27.175.1" port: 43589 } }
I20260812 06:20:25.310385 28558 leader_election.cc:304] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b [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: 6d018000d09e463baf600fffdfa68d6b; no voters: 
I20260812 06:20:25.310573 28558 leader_election.cc:290] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:25.310734 28561 raft_consensus.cc:2804] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:25.310873 28558 ts_tablet_manager.cc:1434] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Time spent starting tablet: real 0.003s	user 0.001s	sys 0.002s
I20260812 06:20:25.310956 28561 raft_consensus.cc:697] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b [term 1 LEADER]: Becoming Leader. State: Replica: 6d018000d09e463baf600fffdfa68d6b, State: Running, Role: LEADER
I20260812 06:20:25.311136 28561 consensus_queue.cc:237] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b [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: "6d018000d09e463baf600fffdfa68d6b" member_type: VOTER last_known_addr { host: "127.27.175.1" port: 43589 } }
I20260812 06:20:25.311288 28544 heartbeater.cc:499] Master 127.27.175.62:44297 was elected leader, sending a full tablet report...
I20260812 06:20:25.314002 28387 catalog_manager.cc:5719] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b reported cstate change: term changed from 0 to 1, leader changed from <none> to 6d018000d09e463baf600fffdfa68d6b (127.27.175.1). New cstate: current_term: 1 leader_uuid: "6d018000d09e463baf600fffdfa68d6b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6d018000d09e463baf600fffdfa68d6b" member_type: VOTER last_known_addr { host: "127.27.175.1" port: 43589 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:25.374958 28348 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.018s	sys 0.006s
I20260812 06:20:25.514923 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushMRSOp(6c70aedd05f34a1daeda281595161051): perf score=19.054940
I20260812 06:20:25.668211 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushMRSOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.153s	user 0.120s	sys 0.029s Metrics: {"bytes_written":9148638,"cfile_init":1,"compiler_manager_pool.queue_time_us":269,"delete_count":0,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":203,"dirs.run_wall_time_us":861,"drs_written":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4,"lbm_write_time_us":37129,"lbm_writes_lt_1ms":680,"mutex_wait_us":181,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":193408,"thread_start_us":162,"threads_started":1,"update_count":1115}
I20260812 06:20:25.669265 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling LogGCOp(6c70aedd05f34a1daeda281595161051): free 20743831 bytes of WAL
I20260812 06:20:25.669602 28472 log_reader.cc:385] T 6c70aedd05f34a1daeda281595161051: removed 2 log segments from log reader
I20260812 06:20:25.669682 28472 log.cc:1079] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/6c70aedd05f34a1daeda281595161051/wal-000000001 (ops 1-6)
I20260812 06:20:25.669759 28472 log.cc:1079] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/6c70aedd05f34a1daeda281595161051/wal-000000002 (ops 7-11)
I20260812 06:20:25.674109 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: LogGCOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.005s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:20:25.674525 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=1.196750
I20260812 06:20:25.692250 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.018s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3159080,"delete_count":0,"lbm_write_time_us":5430,"lbm_writes_lt_1ms":80,"reinsert_count":0,"update_count":385}
I20260812 06:20:25.692876 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051): perf score=1.000000
I20260812 06:20:25.814654 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.122s	user 0.088s	sys 0.025s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16569846,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":895,"lbm_read_time_us":6230,"lbm_reads_lt_1ms":364,"lbm_write_time_us":21550,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":365,"threads_started":5,"update_count":1500}
I20260812 06:20:25.815310 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling UndoDeltaBlockGCOp(6c70aedd05f34a1daeda281595161051): 16411393 bytes on disk
I20260812 06:20:25.815936 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: UndoDeltaBlockGCOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":131,"lbm_reads_lt_1ms":4}
I20260812 06:20:25.816533 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=10.126437
I20260812 06:20:25.860846 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.044s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16713,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:25.861357 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=2.188937
I20260812 06:20:25.877696 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6169,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.878291 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051): perf score=1.000000
I20260812 06:20:26.015228 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.137s	user 0.109s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":763,"lbm_read_time_us":10091,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25340,"lbm_writes_lt_1ms":443,"mutex_wait_us":350,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1152,"update_count":2000}
I20260812 06:20:26.015789 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=10.126437
I20260812 06:20:26.077219 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.061s	user 0.025s	sys 0.027s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":19763,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:26.077771 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=2.188937
I20260812 06:20:26.088778 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4219,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.089262 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051): perf score=1.000000
I20260812 06:20:26.241580 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.152s	user 0.084s	sys 0.064s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":169,"lbm_read_time_us":10961,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22558,"lbm_writes_lt_1ms":443,"mutex_wait_us":56,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2000}
I20260812 06:20:26.242280 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=10.126437
I20260812 06:20:26.290128 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.048s	user 0.019s	sys 0.021s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20483,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:26.290705 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=2.188937
I20260812 06:20:26.301375 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4121,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.302105 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051): perf score=1.000000
I20260812 06:20:26.426692 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.124s	user 0.092s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":173,"lbm_read_time_us":8949,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25309,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11264,"update_count":2000}
I20260812 06:20:26.427277 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=10.126437
I20260812 06:20:26.471192 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.044s	user 0.033s	sys 0.009s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18937,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:26.471786 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=2.188937
I20260812 06:20:26.483363 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4332,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.484002 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051): perf score=1.000000
I20260812 06:20:26.606508 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.122s	user 0.106s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":496,"lbm_read_time_us":8882,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22863,"lbm_writes_lt_1ms":443,"mutex_wait_us":298,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":26240,"update_count":2000}
I20260812 06:20:26.607189 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=10.126437
I20260812 06:20:26.659332 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.052s	user 0.018s	sys 0.031s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17577,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:26.660012 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=2.188937
I20260812 06:20:26.671207 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.011s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4429,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.671674 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051): perf score=1.000000
I20260812 06:20:26.827015 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.155s	user 0.102s	sys 0.046s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":237,"lbm_read_time_us":11009,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24271,"lbm_writes_lt_1ms":443,"mutex_wait_us":63,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:26.827836 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=10.126437
I20260812 06:20:26.877014 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.049s	user 0.021s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16935,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:26.877614 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=2.188937
I20260812 06:20:26.893649 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5902,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.894361 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051): perf score=1.000000
I20260812 06:20:27.028194 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.134s	user 0.116s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1506,"lbm_read_time_us":8688,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26631,"lbm_writes_lt_1ms":443,"mutex_wait_us":533,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2000}
I20260812 06:20:27.028954 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=10.126437
I20260812 06:20:27.077134 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.048s	user 0.020s	sys 0.024s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":23601,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":300,"reinsert_count":0,"update_count":1500}
I20260812 06:20:27.077688 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=2.188937
I20260812 06:20:27.096684 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.019s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6841,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.097344 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushMRSOp(6c70aedd05f34a1daeda281595161051): perf score=1.000000
I20260812 06:20:27.156571 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushMRSOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.059s	user 0.033s	sys 0.004s Metrics: {"bytes_written":1316413,"cfile_init":1,"dirs.queue_time_us":53,"dirs.run_cpu_time_us":248,"dirs.run_wall_time_us":1940,"drs_written":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2623,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:27.157425 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling LogGCOp(6c70aedd05f34a1daeda281595161051): free 124257294 bytes of WAL
I20260812 06:20:27.157670 28472 log_reader.cc:385] T 6c70aedd05f34a1daeda281595161051: removed 12 log segments from log reader
I20260812 06:20:27.157713 28472 log.cc:1079] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/6c70aedd05f34a1daeda281595161051/wal-000000003 (ops 12-16)
I20260812 06:20:27.157743 28472 log.cc:1079] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/6c70aedd05f34a1daeda281595161051/wal-000000004 (ops 17-21)
I20260812 06:20:27.157800 28472 log.cc:1079] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/6c70aedd05f34a1daeda281595161051/wal-000000005 (ops 22-26)
I20260812 06:20:27.157835 28472 log.cc:1079] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/6c70aedd05f34a1daeda281595161051/wal-000000006 (ops 27-31)
I20260812 06:20:27.157876 28472 log.cc:1079] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/6c70aedd05f34a1daeda281595161051/wal-000000007 (ops 32-36)
I20260812 06:20:27.157943 28472 log.cc:1079] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/6c70aedd05f34a1daeda281595161051/wal-000000008 (ops 37-41)
I20260812 06:20:27.157987 28472 log.cc:1079] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/6c70aedd05f34a1daeda281595161051/wal-000000009 (ops 42-46)
I20260812 06:20:27.158030 28472 log.cc:1079] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/6c70aedd05f34a1daeda281595161051/wal-000000010 (ops 47-50)
I20260812 06:20:27.158078 28472 log.cc:1079] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/6c70aedd05f34a1daeda281595161051/wal-000000011 (ops 51-55)
I20260812 06:20:27.158119 28472 log.cc:1079] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/6c70aedd05f34a1daeda281595161051/wal-000000012 (ops 56-60)
I20260812 06:20:27.158159 28472 log.cc:1079] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/6c70aedd05f34a1daeda281595161051/wal-000000013 (ops 61-65)
I20260812 06:20:27.158200 28472 log.cc:1079] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/6c70aedd05f34a1daeda281595161051/wal-000000014 (ops 66-70)
I20260812 06:20:27.187022 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: LogGCOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.029s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:20:27.187515 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=7.149875
I20260812 06:20:27.212452 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.025s	user 0.007s	sys 0.015s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":10710,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:20:27.213038 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling LogGCOp(6c70aedd05f34a1daeda281595161051): free 8767067 bytes of WAL
I20260812 06:20:27.213295 28472 log_reader.cc:385] T 6c70aedd05f34a1daeda281595161051: removed 1 log segments from log reader
I20260812 06:20:27.213361 28472 log.cc:1079] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/6c70aedd05f34a1daeda281595161051/wal-000000015 (ops 71-75)
I20260812 06:20:27.215327 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: LogGCOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.002s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:20:27.215646 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling UndoDeltaBlockGCOp(6c70aedd05f34a1daeda281595161051): 493 bytes on disk
I20260812 06:20:27.216148 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: UndoDeltaBlockGCOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":94,"lbm_reads_lt_1ms":4}
I20260812 06:20:27.216601 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=2.188937
I20260812 06:20:27.233808 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.017s	user 0.011s	sys 0.002s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5896,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:27.234423 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051): perf score=1.000000
I20260812 06:20:27.426614 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.192s	user 0.146s	sys 0.045s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979746,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1181,"lbm_read_time_us":13350,"lbm_reads_lt_1ms":766,"lbm_write_time_us":41223,"lbm_writes_lt_1ms":743,"mutex_wait_us":296,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":14848,"thread_start_us":93,"threads_started":1,"update_count":3500}
I20260812 06:20:27.427409 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=14.095187
I20260812 06:20:27.484387 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.057s	user 0.022s	sys 0.032s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22234,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.485078 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=2.188937
I20260812 06:20:27.521101 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.036s	user 0.009s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5927,"lbm_writes_lt_1ms":103,"mutex_wait_us":19,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.521651 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=2.188937
I20260812 06:20:27.538056 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6156,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.538847 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051): perf score=1.000000
I20260812 06:20:27.738237 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.197s	user 0.137s	sys 0.049s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877218,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":544,"lbm_read_time_us":13753,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35145,"lbm_writes_lt_1ms":643,"mutex_wait_us":26,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":78976,"update_count":3000}
I20260812 06:20:27.739020 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=14.095187
I20260812 06:20:27.803574 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.064s	user 0.041s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":25205,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:20:27.804173 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=2.188937
I20260812 06:20:27.816745 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4859,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.817394 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051): perf score=1.000000
I20260812 06:20:28.004935 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.187s	user 0.147s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1113,"lbm_read_time_us":14145,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33026,"lbm_writes_lt_1ms":543,"mutex_wait_us":322,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:20:28.005615 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=11.118625
I20260812 06:20:28.037755 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.032s	user 0.021s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13886,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:28.038647 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=2.188937
I20260812 06:20:28.056257 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.017s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4914,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:28.056735 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051): perf score=1.000000
I20260812 06:20:28.223740 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.167s	user 0.111s	sys 0.047s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":743,"lbm_read_time_us":8639,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27325,"lbm_writes_lt_1ms":443,"mutex_wait_us":77,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9728,"update_count":2000}
I20260812 06:20:28.224689 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=11.118625
I20260812 06:20:28.268505 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.044s	user 0.030s	sys 0.012s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":19100,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:28.269122 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=2.188937
I20260812 06:20:28.295913 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.027s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5046,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:28.296389 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=2.188937
I20260812 06:20:28.307144 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4171,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.307621 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051): perf score=1.000000
I20260812 06:20:28.463318 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.156s	user 0.110s	sys 0.045s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":64,"lbm_read_time_us":10537,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32445,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20096,"update_count":2500}
I20260812 06:20:28.464030 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=10.126437
I20260812 06:20:28.502090 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.038s	user 0.019s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16079,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:28.502867 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=2.188937
I20260812 06:20:28.521292 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.018s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6864,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.522046 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051): perf score=1.000000
I20260812 06:20:28.663810 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.142s	user 0.109s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":437,"lbm_read_time_us":12152,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27065,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2000}
I20260812 06:20:28.664721 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=10.126437
I20260812 06:20:28.729314 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.064s	user 0.024s	sys 0.025s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18771,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:28.729982 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=2.188937
I20260812 06:20:28.741124 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4369,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.741776 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushMRSOp(6c70aedd05f34a1daeda281595161051): perf score=1.000000
I20260812 06:20:28.787037 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushMRSOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.045s	user 0.032s	sys 0.005s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":87,"dirs.run_cpu_time_us":200,"dirs.run_wall_time_us":2527,"drs_written":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1495,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:28.787868 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling LogGCOp(6c70aedd05f34a1daeda281595161051): free 124257323 bytes of WAL
I20260812 06:20:28.788110 28472 log_reader.cc:385] T 6c70aedd05f34a1daeda281595161051: removed 12 log segments from log reader
I20260812 06:20:28.788156 28472 log.cc:1079] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/6c70aedd05f34a1daeda281595161051/wal-000000016 (ops 76-80)
I20260812 06:20:28.788188 28472 log.cc:1079] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/6c70aedd05f34a1daeda281595161051/wal-000000017 (ops 81-85)
I20260812 06:20:28.788257 28472 log.cc:1079] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/6c70aedd05f34a1daeda281595161051/wal-000000018 (ops 86-90)
I20260812 06:20:28.788291 28472 log.cc:1079] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/6c70aedd05f34a1daeda281595161051/wal-000000019 (ops 91-95)
I20260812 06:20:28.788334 28472 log.cc:1079] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/6c70aedd05f34a1daeda281595161051/wal-000000020 (ops 96-100)
I20260812 06:20:28.788389 28472 log.cc:1079] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/6c70aedd05f34a1daeda281595161051/wal-000000021 (ops 101-105)
I20260812 06:20:28.788430 28472 log.cc:1079] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/6c70aedd05f34a1daeda281595161051/wal-000000022 (ops 106-110)
I20260812 06:20:28.788473 28472 log.cc:1079] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/6c70aedd05f34a1daeda281595161051/wal-000000023 (ops 111-115)
I20260812 06:20:28.788508 28472 log.cc:1079] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/6c70aedd05f34a1daeda281595161051/wal-000000024 (ops 116-120)
I20260812 06:20:28.788547 28472 log.cc:1079] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/6c70aedd05f34a1daeda281595161051/wal-000000025 (ops 121-124)
I20260812 06:20:28.788587 28472 log.cc:1079] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/6c70aedd05f34a1daeda281595161051/wal-000000026 (ops 125-129)
I20260812 06:20:28.788627 28472 log.cc:1079] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/6c70aedd05f34a1daeda281595161051/wal-000000027 (ops 130-134)
I20260812 06:20:28.821295 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: LogGCOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.033s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:20:28.821843 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling UndoDeltaBlockGCOp(6c70aedd05f34a1daeda281595161051): 472 bytes on disk
I20260812 06:20:28.822628 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: UndoDeltaBlockGCOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":160,"lbm_reads_lt_1ms":4}
I20260812 06:20:28.823263 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=3.181125
I20260812 06:20:28.845155 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.022s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4633,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:28.845777 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=2.188937
I20260812 06:20:28.857694 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3812,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:28.858346 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051): perf score=1.000000
I20260812 06:20:29.067831 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.209s	user 0.132s	sys 0.076s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":364,"lbm_read_time_us":15874,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36236,"lbm_writes_lt_1ms":643,"mutex_wait_us":163,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":84,"threads_started":1,"update_count":3000}
I20260812 06:20:29.068701 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=14.095187
I20260812 06:20:29.122972 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.054s	user 0.043s	sys 0.008s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":23249,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.123544 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051): perf score=1.000000
I20260812 06:20:29.274372 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.151s	user 0.103s	sys 0.040s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672156,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":665,"lbm_read_time_us":10386,"lbm_reads_lt_1ms":463,"lbm_write_time_us":24140,"lbm_writes_lt_1ms":443,"mutex_wait_us":319,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12800,"update_count":2000}
I20260812 06:20:29.275063 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=14.095187
I20260812 06:20:29.332341 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.057s	user 0.041s	sys 0.009s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":22752,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.332896 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=2.188937
I20260812 06:20:29.345412 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4698,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.345906 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051): perf score=1.000000
I20260812 06:20:29.558499 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.212s	user 0.131s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2168,"lbm_read_time_us":11481,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32574,"lbm_writes_lt_1ms":543,"mutex_wait_us":406,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2500}
I20260812 06:20:29.559237 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=14.095187
I20260812 06:20:29.616878 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.057s	user 0.026s	sys 0.028s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":25393,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.617542 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=2.188937
I20260812 06:20:29.637128 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.019s	user 0.003s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6129,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.637759 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051): perf score=1.000000
I20260812 06:20:29.789458 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.151s	user 0.120s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":334,"lbm_read_time_us":10385,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28174,"lbm_writes_lt_1ms":543,"mutex_wait_us":60,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9344,"update_count":2500}
I20260812 06:20:29.790087 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=14.095187
I20260812 06:20:29.845827 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.056s	user 0.023s	sys 0.019s Metrics: {"bytes_written":16409897,"delete_count":0,"lbm_write_time_us":20382,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.846472 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=2.188937
I20260812 06:20:29.858950 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4363,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.859591 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051): perf score=1.000000
I20260812 06:20:30.019621 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.160s	user 0.120s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1124,"lbm_read_time_us":9574,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31345,"lbm_writes_lt_1ms":543,"mutex_wait_us":332,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9728,"update_count":2500}
I20260812 06:20:30.020145 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=14.095187
I20260812 06:20:30.072696 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.052s	user 0.029s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19844,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:30.073379 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=2.188937
I20260812 06:20:30.085875 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4511,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.086468 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051): perf score=1.000000
I20260812 06:20:30.237839 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.151s	user 0.122s	sys 0.029s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":891,"lbm_read_time_us":11917,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31444,"lbm_writes_lt_1ms":543,"mutex_wait_us":357,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4608,"update_count":2500}
I20260812 06:20:30.238631 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=10.126437
I20260812 06:20:30.285043 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.046s	user 0.026s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15577,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:30.285718 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=2.188937
I20260812 06:20:30.298470 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.013s	user 0.001s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4575,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.298969 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushMRSOp(6c70aedd05f34a1daeda281595161051): perf score=1.000000
I20260812 06:20:30.327778 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushMRSOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.029s	user 0.026s	sys 0.001s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":80,"dirs.run_cpu_time_us":229,"dirs.run_wall_time_us":1669,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1750,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30,"spinlock_wait_cycles":38784}
I20260812 06:20:30.328660 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling LogGCOp(6c70aedd05f34a1daeda281595161051): free 121006640 bytes of WAL
I20260812 06:20:30.328907 28472 log_reader.cc:385] T 6c70aedd05f34a1daeda281595161051: removed 12 log segments from log reader
I20260812 06:20:30.328981 28472 log.cc:1079] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/6c70aedd05f34a1daeda281595161051/wal-000000028 (ops 135-139)
I20260812 06:20:30.329033 28472 log.cc:1079] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/6c70aedd05f34a1daeda281595161051/wal-000000029 (ops 140-144)
I20260812 06:20:30.329077 28472 log.cc:1079] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/6c70aedd05f34a1daeda281595161051/wal-000000030 (ops 145-149)
I20260812 06:20:30.329174 28472 log.cc:1079] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/6c70aedd05f34a1daeda281595161051/wal-000000031 (ops 150-154)
I20260812 06:20:30.329267 28472 log.cc:1079] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/6c70aedd05f34a1daeda281595161051/wal-000000032 (ops 155-159)
I20260812 06:20:30.329331 28472 log.cc:1079] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/6c70aedd05f34a1daeda281595161051/wal-000000033 (ops 160-164)
I20260812 06:20:30.329401 28472 log.cc:1079] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/6c70aedd05f34a1daeda281595161051/wal-000000034 (ops 165-168)
I20260812 06:20:30.329442 28472 log.cc:1079] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/6c70aedd05f34a1daeda281595161051/wal-000000035 (ops 169-173)
I20260812 06:20:30.329514 28472 log.cc:1079] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/6c70aedd05f34a1daeda281595161051/wal-000000036 (ops 174-178)
I20260812 06:20:30.329588 28472 log.cc:1079] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/6c70aedd05f34a1daeda281595161051/wal-000000037 (ops 179-183)
I20260812 06:20:30.329645 28472 log.cc:1079] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/6c70aedd05f34a1daeda281595161051/wal-000000038 (ops 184-188)
I20260812 06:20:30.329674 28472 log.cc:1079] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/6c70aedd05f34a1daeda281595161051/wal-000000039 (ops 189-193)
I20260812 06:20:30.361186 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: LogGCOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.032s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:20:30.361898 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling UndoDeltaBlockGCOp(6c70aedd05f34a1daeda281595161051): 472 bytes on disk
I20260812 06:20:30.362676 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: UndoDeltaBlockGCOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":79,"lbm_reads_lt_1ms":4}
I20260812 06:20:30.363297 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=3.181125
I20260812 06:20:30.376055 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4719,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:30.376569 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=2.188937
I20260812 06:20:30.391575 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5334,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:30.392201 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051): perf score=1.000000
I20260812 06:20:30.465085 28348 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.090s	user 1.877s	sys 0.164s
I20260812 06:20:30.552498 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: MajorDeltaCompactionOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.160s	user 0.112s	sys 0.048s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1086,"lbm_read_time_us":12346,"lbm_reads_lt_1ms":670,"lbm_write_time_us":31618,"lbm_writes_lt_1ms":643,"mutex_wait_us":21,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":20224,"thread_start_us":106,"threads_started":1,"update_count":3000}
I20260812 06:20:30.553143 28545 maintenance_manager.cc:419] P 6d018000d09e463baf600fffdfa68d6b: Scheduling FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051): perf score=6.157687
I20260812 06:20:30.557467 28348 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.092s	user 0.002s	sys 0.000s
I20260812 06:20:30.558125 28348 tablet_server.cc:179] TabletServer@127.27.175.1:0 shutting down...
I20260812 06:20:30.577543 28472 maintenance_manager.cc:643] P 6d018000d09e463baf600fffdfa68d6b: FlushDeltaMemStoresOp(6c70aedd05f34a1daeda281595161051) complete. Timing: real 0.024s	user 0.014s	sys 0.007s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9947,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:20:30.578286 28348 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:30.578719 28348 tablet_replica.cc:333] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b: stopping tablet replica
I20260812 06:20:30.578982 28348 raft_consensus.cc:2243] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:30.579227 28348 raft_consensus.cc:2272] T 6c70aedd05f34a1daeda281595161051 P 6d018000d09e463baf600fffdfa68d6b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:30.595100 28348 tablet_server.cc:196] TabletServer@127.27.175.1:0 shutdown complete.
I20260812 06:20:30.606045 28348 master.cc:562] Master@127.27.175.62:44297 shutting down...
I20260812 06:20:30.610512 28348 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 9f121159b6b3459db8ce375a593bca74 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:30.610734 28348 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 9f121159b6b3459db8ce375a593bca74 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:30.610845 28348 tablet_replica.cc:333] T 00000000000000000000000000000000 P 9f121159b6b3459db8ce375a593bca74: stopping tablet replica
I20260812 06:20:30.623476 28348 master.cc:584] Master@127.27.175.62:44297 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5659 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:30.724905 28348 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.27.175.62:33183
I20260812 06:20:30.725275 28348 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:30.727388 28580 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:30.727545 28582 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:30.727615 28348 server_base.cc:1061] running on GCE node
W20260812 06:20:30.727573 28586 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:30.727876 28348 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:30.727928 28348 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:30.727946 28348 hybrid_clock.cc:648] HybridClock initialized: now 1786515630727946 us; error 0 us; skew 500 ppm
I20260812 06:20:30.728933 28348 webserver.cc:533] Webserver started at http://127.27.175.62:43065/ using document root <none> and password file <none>
I20260812 06:20:30.729139 28348 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:30.729218 28348 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:30.729321 28348 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:30.729774 28348 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/master-0-root/instance:
uuid: "e089cb2ed6e743a7a022828e4b044f80"
format_stamp: "Formatted at 2026-08-12 06:20:30 on dist-test-slave-tm1g"
I20260812 06:20:30.731570 28348 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:20:30.732653 28592 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:30.732939 28348 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:30.733016 28348 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/master-0-root
uuid: "e089cb2ed6e743a7a022828e4b044f80"
format_stamp: "Formatted at 2026-08-12 06:20:30 on dist-test-slave-tm1g"
I20260812 06:20:30.733078 28348 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:30.749678 28348 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:30.750069 28348 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:30.754153 28348 rpc_server.cc:307] RPC server started. Bound to: 127.27.175.62:33183
I20260812 06:20:30.757921 28650 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:30.767112 28648 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.175.62:33183 every 8 connection(s)
I20260812 06:20:30.774951 28650 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e089cb2ed6e743a7a022828e4b044f80: Bootstrap starting.
I20260812 06:20:30.775965 28650 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P e089cb2ed6e743a7a022828e4b044f80: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:30.777222 28650 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e089cb2ed6e743a7a022828e4b044f80: No bootstrap required, opened a new log
I20260812 06:20:30.777681 28650 raft_consensus.cc:359] T 00000000000000000000000000000000 P e089cb2ed6e743a7a022828e4b044f80 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e089cb2ed6e743a7a022828e4b044f80" member_type: VOTER }
I20260812 06:20:30.777804 28650 raft_consensus.cc:385] T 00000000000000000000000000000000 P e089cb2ed6e743a7a022828e4b044f80 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:30.777855 28650 raft_consensus.cc:740] T 00000000000000000000000000000000 P e089cb2ed6e743a7a022828e4b044f80 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e089cb2ed6e743a7a022828e4b044f80, State: Initialized, Role: FOLLOWER
I20260812 06:20:30.778052 28650 consensus_queue.cc:260] T 00000000000000000000000000000000 P e089cb2ed6e743a7a022828e4b044f80 [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: "e089cb2ed6e743a7a022828e4b044f80" member_type: VOTER }
I20260812 06:20:30.778152 28650 raft_consensus.cc:399] T 00000000000000000000000000000000 P e089cb2ed6e743a7a022828e4b044f80 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:30.778201 28650 raft_consensus.cc:493] T 00000000000000000000000000000000 P e089cb2ed6e743a7a022828e4b044f80 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:30.778259 28650 raft_consensus.cc:3060] T 00000000000000000000000000000000 P e089cb2ed6e743a7a022828e4b044f80 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:30.779080 28650 raft_consensus.cc:515] T 00000000000000000000000000000000 P e089cb2ed6e743a7a022828e4b044f80 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e089cb2ed6e743a7a022828e4b044f80" member_type: VOTER }
I20260812 06:20:30.779244 28650 leader_election.cc:304] T 00000000000000000000000000000000 P e089cb2ed6e743a7a022828e4b044f80 [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: e089cb2ed6e743a7a022828e4b044f80; no voters: 
I20260812 06:20:30.779471 28650 leader_election.cc:290] T 00000000000000000000000000000000 P e089cb2ed6e743a7a022828e4b044f80 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:30.779677 28654 raft_consensus.cc:2804] T 00000000000000000000000000000000 P e089cb2ed6e743a7a022828e4b044f80 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:30.779938 28654 raft_consensus.cc:697] T 00000000000000000000000000000000 P e089cb2ed6e743a7a022828e4b044f80 [term 1 LEADER]: Becoming Leader. State: Replica: e089cb2ed6e743a7a022828e4b044f80, State: Running, Role: LEADER
I20260812 06:20:30.780064 28650 sys_catalog.cc:565] T 00000000000000000000000000000000 P e089cb2ed6e743a7a022828e4b044f80 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:30.780153 28654 consensus_queue.cc:237] T 00000000000000000000000000000000 P e089cb2ed6e743a7a022828e4b044f80 [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: "e089cb2ed6e743a7a022828e4b044f80" member_type: VOTER }
I20260812 06:20:30.780644 28656 sys_catalog.cc:455] T 00000000000000000000000000000000 P e089cb2ed6e743a7a022828e4b044f80 [sys.catalog]: SysCatalogTable state changed. Reason: New leader e089cb2ed6e743a7a022828e4b044f80. Latest consensus state: current_term: 1 leader_uuid: "e089cb2ed6e743a7a022828e4b044f80" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e089cb2ed6e743a7a022828e4b044f80" member_type: VOTER } }
I20260812 06:20:30.780624 28655 sys_catalog.cc:455] T 00000000000000000000000000000000 P e089cb2ed6e743a7a022828e4b044f80 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "e089cb2ed6e743a7a022828e4b044f80" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e089cb2ed6e743a7a022828e4b044f80" member_type: VOTER } }
I20260812 06:20:30.780742 28656 sys_catalog.cc:458] T 00000000000000000000000000000000 P e089cb2ed6e743a7a022828e4b044f80 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:30.780755 28655 sys_catalog.cc:458] T 00000000000000000000000000000000 P e089cb2ed6e743a7a022828e4b044f80 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:30.781050 28659 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:30.781910 28659 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:30.782212 28348 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:30.784036 28659 catalog_manager.cc:1383] Generated new cluster ID: 44251bc24e624a84850999d73812a92d
I20260812 06:20:30.784099 28659 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:30.804436 28659 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:30.805075 28659 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:30.816790 28659 catalog_manager.cc:6092] T 00000000000000000000000000000000 P e089cb2ed6e743a7a022828e4b044f80: Generated new TSK 0
I20260812 06:20:30.817005 28659 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:30.847563 28348 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:20:30.850039 28348 server_base.cc:1061] running on GCE node
W20260812 06:20:30.850106 28675 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:20:30.850119 28674 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:30.850035 28678 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:30.850528 28348 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:30.850576 28348 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:30.850600 28348 hybrid_clock.cc:648] HybridClock initialized: now 1786515630850599 us; error 0 us; skew 500 ppm
I20260812 06:20:30.851629 28348 webserver.cc:533] Webserver started at http://127.27.175.1:35423/ using document root <none> and password file <none>
I20260812 06:20:30.851825 28348 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:30.851881 28348 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:30.852017 28348 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:30.852460 28348 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/instance:
uuid: "8c77724efb5745b9a76fc09e7b9d2061"
format_stamp: "Formatted at 2026-08-12 06:20:30 on dist-test-slave-tm1g"
I20260812 06:20:30.854068 28348 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:30.855163 28683 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:30.855487 28348 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:30.855567 28348 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root
uuid: "8c77724efb5745b9a76fc09e7b9d2061"
format_stamp: "Formatted at 2026-08-12 06:20:30 on dist-test-slave-tm1g"
I20260812 06:20:30.855697 28348 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:30.862788 28348 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:30.863219 28348 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:30.863565 28348 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:30.864092 28348 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:30.864135 28348 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:30.864173 28348 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:30.864238 28348 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:30.868922 28348 rpc_server.cc:307] RPC server started. Bound to: 127.27.175.1:36793
I20260812 06:20:30.868985 28754 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.175.1:36793 every 8 connection(s)
I20260812 06:20:30.880213 28755 heartbeater.cc:344] Connected to a master server at 127.27.175.62:33183
I20260812 06:20:30.880355 28755 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:30.880704 28755 heartbeater.cc:507] Master 127.27.175.62:33183 requested a full tablet report, sending...
I20260812 06:20:30.881510 28610 ts_manager.cc:194] Registered new tserver with Master: 8c77724efb5745b9a76fc09e7b9d2061 (127.27.175.1:36793)
I20260812 06:20:30.881820 28348 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012366042s
I20260812 06:20:30.882560 28610 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:36706
I20260812 06:20:30.889741 28610 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:36720:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:30.899312 28713 tablet_service.cc:1511] Processing CreateTablet for tablet b702b94ab960437dacb0dafe0416ef5a (DEFAULT_TABLE table=heavy-update-compaction-test [id=336b2f0db9b84664898ae025ebbd2802]), partition=
I20260812 06:20:30.899619 28713 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet b702b94ab960437dacb0dafe0416ef5a. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:30.901537 28770 tablet_bootstrap.cc:492] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Bootstrap starting.
I20260812 06:20:30.902458 28770 tablet_bootstrap.cc:654] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:30.903581 28770 tablet_bootstrap.cc:492] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: No bootstrap required, opened a new log
I20260812 06:20:30.903692 28770 ts_tablet_manager.cc:1403] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:20:30.904170 28770 raft_consensus.cc:359] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8c77724efb5745b9a76fc09e7b9d2061" member_type: VOTER last_known_addr { host: "127.27.175.1" port: 36793 } }
I20260812 06:20:30.904284 28770 raft_consensus.cc:385] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:30.904331 28770 raft_consensus.cc:740] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 8c77724efb5745b9a76fc09e7b9d2061, State: Initialized, Role: FOLLOWER
I20260812 06:20:30.904525 28770 consensus_queue.cc:260] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061 [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: "8c77724efb5745b9a76fc09e7b9d2061" member_type: VOTER last_known_addr { host: "127.27.175.1" port: 36793 } }
I20260812 06:20:30.904641 28770 raft_consensus.cc:399] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:30.904690 28770 raft_consensus.cc:493] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:30.904747 28770 raft_consensus.cc:3060] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:30.905592 28770 raft_consensus.cc:515] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8c77724efb5745b9a76fc09e7b9d2061" member_type: VOTER last_known_addr { host: "127.27.175.1" port: 36793 } }
I20260812 06:20:30.905754 28770 leader_election.cc:304] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061 [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: 8c77724efb5745b9a76fc09e7b9d2061; no voters: 
I20260812 06:20:30.905972 28770 leader_election.cc:290] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:30.906087 28772 raft_consensus.cc:2804] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:30.906342 28772 raft_consensus.cc:697] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061 [term 1 LEADER]: Becoming Leader. State: Replica: 8c77724efb5745b9a76fc09e7b9d2061, State: Running, Role: LEADER
I20260812 06:20:30.906430 28755 heartbeater.cc:499] Master 127.27.175.62:33183 was elected leader, sending a full tablet report...
I20260812 06:20:30.906540 28770 ts_tablet_manager.cc:1434] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:20:30.906592 28772 consensus_queue.cc:237] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061 [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: "8c77724efb5745b9a76fc09e7b9d2061" member_type: VOTER last_known_addr { host: "127.27.175.1" port: 36793 } }
I20260812 06:20:30.908054 28610 catalog_manager.cc:5719] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061 reported cstate change: term changed from 0 to 1, leader changed from <none> to 8c77724efb5745b9a76fc09e7b9d2061 (127.27.175.1). New cstate: current_term: 1 leader_uuid: "8c77724efb5745b9a76fc09e7b9d2061" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8c77724efb5745b9a76fc09e7b9d2061" member_type: VOTER last_known_addr { host: "127.27.175.1" port: 36793 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:30.972373 28348 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.057s	user 0.017s	sys 0.008s
I20260812 06:20:31.120020 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushMRSOp(b702b94ab960437dacb0dafe0416ef5a): perf score=19.054940
I20260812 06:20:31.285247 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushMRSOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.165s	user 0.134s	sys 0.028s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":114,"dirs.run_cpu_time_us":229,"dirs.run_wall_time_us":979,"drs_written":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4,"lbm_write_time_us":42124,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:20:31.285866 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling LogGCOp(b702b94ab960437dacb0dafe0416ef5a): free 20743880 bytes of WAL
I20260812 06:20:31.286093 28688 log_reader.cc:385] T b702b94ab960437dacb0dafe0416ef5a: removed 2 log segments from log reader
I20260812 06:20:31.286139 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000001 (ops 1-6)
I20260812 06:20:31.286190 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000002 (ops 7-11)
I20260812 06:20:31.290508 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: LogGCOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.004s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:20:31.290874 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling UndoDeltaBlockGCOp(b702b94ab960437dacb0dafe0416ef5a): 16411393 bytes on disk
I20260812 06:20:31.291339 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: UndoDeltaBlockGCOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:20:31.292292 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=2.188937
I20260812 06:20:31.305698 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.013s	user 0.001s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4907,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.306273 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling MajorDeltaCompactionOp(b702b94ab960437dacb0dafe0416ef5a): perf score=1.000000
I20260812 06:20:31.457468 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: MajorDeltaCompactionOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.151s	user 0.119s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":650,"lbm_read_time_us":10656,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26564,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":326,"threads_started":5,"update_count":2000}
I20260812 06:20:31.458135 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=14.095187
I20260812 06:20:31.516662 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.058s	user 0.048s	sys 0.007s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25364,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:31.517225 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=2.188937
I20260812 06:20:31.530419 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.013s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4461,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.530933 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling MajorDeltaCompactionOp(b702b94ab960437dacb0dafe0416ef5a): perf score=1.000000
I20260812 06:20:31.695917 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: MajorDeltaCompactionOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.165s	user 0.136s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":316,"lbm_read_time_us":10547,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32638,"lbm_writes_lt_1ms":543,"mutex_wait_us":65,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2500}
I20260812 06:20:31.696687 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=11.118625
I20260812 06:20:31.747090 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.050s	user 0.042s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":21494,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:31.748104 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=2.188937
I20260812 06:20:31.763989 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.016s	user 0.009s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6009,"lbm_writes_lt_1ms":93,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":450}
I20260812 06:20:31.764537 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling MajorDeltaCompactionOp(b702b94ab960437dacb0dafe0416ef5a): perf score=1.000000
I20260812 06:20:31.935451 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: MajorDeltaCompactionOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.170s	user 0.116s	sys 0.053s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":928,"lbm_read_time_us":12769,"lbm_reads_lt_1ms":468,"lbm_write_time_us":27933,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18176,"update_count":2000}
I20260812 06:20:31.936276 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=10.126437
I20260812 06:20:31.973094 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.037s	user 0.025s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14847,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:31.973816 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=2.188937
I20260812 06:20:32.004000 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.030s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7286,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:32.004547 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=2.188937
I20260812 06:20:32.028086 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.023s	user 0.009s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4553,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:32.028738 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling MajorDeltaCompactionOp(b702b94ab960437dacb0dafe0416ef5a): perf score=1.000000
I20260812 06:20:32.226799 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: MajorDeltaCompactionOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.198s	user 0.125s	sys 0.072s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774808,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1353,"lbm_read_time_us":13333,"lbm_reads_lt_1ms":573,"lbm_write_time_us":34041,"lbm_writes_lt_1ms":543,"mutex_wait_us":573,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":21760,"update_count":2500}
I20260812 06:20:32.227412 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=14.095187
I20260812 06:20:32.285077 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.057s	user 0.029s	sys 0.024s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":24614,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:32.285591 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=2.188937
I20260812 06:20:32.297786 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4354,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:32.298493 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling MajorDeltaCompactionOp(b702b94ab960437dacb0dafe0416ef5a): perf score=1.000000
I20260812 06:20:32.491636 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: MajorDeltaCompactionOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.193s	user 0.115s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":407,"lbm_read_time_us":10314,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32180,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":74880,"update_count":2500}
I20260812 06:20:32.492390 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=14.095187
I20260812 06:20:32.547973 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.055s	user 0.018s	sys 0.036s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26905,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:32.548674 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=2.188937
I20260812 06:20:32.565518 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.017s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5942,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:32.566082 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushMRSOp(b702b94ab960437dacb0dafe0416ef5a): perf score=1.000000
I20260812 06:20:32.625765 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushMRSOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.060s	user 0.036s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":296,"dirs.run_wall_time_us":1783,"drs_written":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1897,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:32.628557 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=6.157687
I20260812 06:20:32.649206 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.020s	user 0.015s	sys 0.003s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":8897,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:20:32.649904 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling LogGCOp(b702b94ab960437dacb0dafe0416ef5a): free 120553376 bytes of WAL
I20260812 06:20:32.650558 28688 log_reader.cc:385] T b702b94ab960437dacb0dafe0416ef5a: removed 12 log segments from log reader
I20260812 06:20:32.650704 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000003 (ops 12-16)
I20260812 06:20:32.650835 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000004 (ops 17-21)
I20260812 06:20:32.650938 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000005 (ops 22-26)
I20260812 06:20:32.651050 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000006 (ops 27-31)
I20260812 06:20:32.651150 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000007 (ops 32-36)
I20260812 06:20:32.651250 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000008 (ops 37-40)
I20260812 06:20:32.651343 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000009 (ops 41-45)
I20260812 06:20:32.651409 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000010 (ops 46-50)
I20260812 06:20:32.651449 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000011 (ops 51-55)
I20260812 06:20:32.651515 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000012 (ops 56-60)
I20260812 06:20:32.651564 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000013 (ops 61-64)
I20260812 06:20:32.651648 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000014 (ops 65-69)
I20260812 06:20:32.679347 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: LogGCOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.029s	user 0.004s	sys 0.024s Metrics: {}
I20260812 06:20:32.679996 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling UndoDeltaBlockGCOp(b702b94ab960437dacb0dafe0416ef5a): 462 bytes on disk
I20260812 06:20:32.680493 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: UndoDeltaBlockGCOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:20:32.681007 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=2.188937
I20260812 06:20:32.691497 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3487284,"delete_count":0,"lbm_write_time_us":3963,"lbm_writes_lt_1ms":88,"reinsert_count":0,"update_count":425}
I20260812 06:20:32.691994 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling MajorDeltaCompactionOp(b702b94ab960437dacb0dafe0416ef5a): perf score=1.000000
I20260812 06:20:32.957154 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: MajorDeltaCompactionOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.265s	user 0.148s	sys 0.115s Metrics: {"cfile_cache_miss":819,"cfile_cache_miss_bytes":36466788,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1377,"lbm_read_time_us":19840,"lbm_reads_lt_1ms":855,"lbm_write_time_us":44519,"lbm_writes_lt_1ms":828,"mutex_wait_us":813,"peak_mem_usage":97699323,"reinsert_count":0,"spinlock_wait_cycles":32896,"thread_start_us":89,"threads_started":1,"update_count":3925}
I20260812 06:20:32.957985 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=19.056125
I20260812 06:20:33.029614 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.071s	user 0.036s	sys 0.031s Metrics: {"bytes_written":21127681,"delete_count":0,"lbm_write_time_us":30829,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":517,"reinsert_count":0,"update_count":2575}
I20260812 06:20:33.030431 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=2.188937
I20260812 06:20:33.046687 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5746,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:33.047513 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling MajorDeltaCompactionOp(b702b94ab960437dacb0dafe0416ef5a): perf score=1.000000
I20260812 06:20:33.282665 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: MajorDeltaCompactionOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.235s	user 0.157s	sys 0.068s Metrics: {"cfile_cache_miss":647,"cfile_cache_miss_bytes":29492468,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1101,"lbm_read_time_us":16026,"lbm_reads_lt_1ms":679,"lbm_write_time_us":36636,"lbm_writes_lt_1ms":658,"mutex_wait_us":361,"peak_mem_usage":77198381,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":3075}
I20260812 06:20:33.283427 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=18.063937
I20260812 06:20:33.353986 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.070s	user 0.044s	sys 0.021s Metrics: {"bytes_written":20512319,"delete_count":0,"lbm_write_time_us":31901,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:20:33.354592 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=2.188937
I20260812 06:20:33.371443 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.017s	user 0.014s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6427,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:33.372427 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling MajorDeltaCompactionOp(b702b94ab960437dacb0dafe0416ef5a): perf score=1.000000
I20260812 06:20:33.602665 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: MajorDeltaCompactionOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.230s	user 0.156s	sys 0.073s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877106,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":159,"lbm_read_time_us":15726,"lbm_reads_lt_1ms":664,"lbm_write_time_us":38928,"lbm_writes_lt_1ms":643,"mutex_wait_us":23,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":3000}
I20260812 06:20:33.603374 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=14.095187
I20260812 06:20:33.651757 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.048s	user 0.034s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21674,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:33.652262 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=2.188937
I20260812 06:20:33.677999 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.026s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5892,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:33.678493 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=2.188937
I20260812 06:20:33.689949 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4384,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:33.690526 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling MajorDeltaCompactionOp(b702b94ab960437dacb0dafe0416ef5a): perf score=1.000000
I20260812 06:20:33.907847 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: MajorDeltaCompactionOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.217s	user 0.141s	sys 0.073s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877221,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1034,"lbm_read_time_us":13664,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34760,"lbm_writes_lt_1ms":643,"mutex_wait_us":331,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":17920,"update_count":3000}
I20260812 06:20:33.908492 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=16.079562
I20260812 06:20:33.960323 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.052s	user 0.030s	sys 0.019s Metrics: {"bytes_written":17763699,"delete_count":0,"lbm_write_time_us":22562,"lbm_writes_lt_1ms":436,"reinsert_count":0,"update_count":2165}
I20260812 06:20:33.960978 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=1.196750
I20260812 06:20:33.984153 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.023s	user 0.008s	sys 0.001s Metrics: {"bytes_written":2748830,"delete_count":0,"lbm_write_time_us":3737,"lbm_writes_lt_1ms":70,"reinsert_count":0,"update_count":335}
I20260812 06:20:33.984664 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=2.188937
I20260812 06:20:33.995467 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.011s	user 0.003s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3989,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:33.995972 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling MajorDeltaCompactionOp(b702b94ab960437dacb0dafe0416ef5a): perf score=1.000000
I20260812 06:20:34.214576 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: MajorDeltaCompactionOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.218s	user 0.131s	sys 0.085s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877188,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1047,"lbm_read_time_us":16051,"lbm_reads_lt_1ms":673,"lbm_write_time_us":36867,"lbm_writes_lt_1ms":643,"mutex_wait_us":26,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":19840,"update_count":3000}
I20260812 06:20:34.215241 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=16.079562
I20260812 06:20:34.279037 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.064s	user 0.038s	sys 0.021s Metrics: {"bytes_written":17886767,"delete_count":0,"lbm_write_time_us":26275,"lbm_writes_lt_1ms":439,"reinsert_count":0,"update_count":2180}
I20260812 06:20:34.279680 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=1.196750
I20260812 06:20:34.297571 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.018s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3036009,"delete_count":0,"lbm_write_time_us":5472,"lbm_writes_lt_1ms":77,"reinsert_count":0,"update_count":370}
I20260812 06:20:34.298137 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=2.188937
I20260812 06:20:34.309060 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3982,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:34.309885 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushMRSOp(b702b94ab960437dacb0dafe0416ef5a): perf score=1.000000
I20260812 06:20:34.347298 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushMRSOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.037s	user 0.036s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":236,"dirs.run_wall_time_us":1422,"drs_written":1,"lbm_read_time_us":99,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1735,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:34.348284 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling LogGCOp(b702b94ab960437dacb0dafe0416ef5a): free 129320542 bytes of WAL
I20260812 06:20:34.348577 28688 log_reader.cc:385] T b702b94ab960437dacb0dafe0416ef5a: removed 13 log segments from log reader
I20260812 06:20:34.348623 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000015 (ops 70-74)
I20260812 06:20:34.348654 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000016 (ops 75-78)
I20260812 06:20:34.348701 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000017 (ops 79-83)
I20260812 06:20:34.348744 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000018 (ops 84-88)
I20260812 06:20:34.348798 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000019 (ops 89-93)
I20260812 06:20:34.348843 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000020 (ops 94-98)
I20260812 06:20:34.348887 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000021 (ops 99-102)
I20260812 06:20:34.348932 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000022 (ops 103-107)
I20260812 06:20:34.348974 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000023 (ops 108-112)
I20260812 06:20:34.349015 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000024 (ops 113-117)
I20260812 06:20:34.349056 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000025 (ops 118-122)
I20260812 06:20:34.349095 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000026 (ops 123-127)
I20260812 06:20:34.349135 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000027 (ops 128-132)
I20260812 06:20:34.380191 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: LogGCOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.032s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:20:34.381527 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling UndoDeltaBlockGCOp(b702b94ab960437dacb0dafe0416ef5a): 493 bytes on disk
I20260812 06:20:34.381969 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: UndoDeltaBlockGCOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:20:34.382519 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=6.157687
I20260812 06:20:34.403028 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.020s	user 0.016s	sys 0.004s Metrics: {"bytes_written":7753812,"delete_count":0,"lbm_write_time_us":7971,"lbm_writes_lt_1ms":192,"reinsert_count":0,"update_count":945}
I20260812 06:20:34.403525 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling MajorDeltaCompactionOp(b702b94ab960437dacb0dafe0416ef5a): perf score=1.000000
I20260812 06:20:34.646641 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: MajorDeltaCompactionOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.243s	user 0.157s	sys 0.084s Metrics: {"cfile_cache_miss":823,"cfile_cache_miss_bytes":36630859,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1882,"lbm_read_time_us":17735,"lbm_reads_lt_1ms":855,"lbm_write_time_us":44432,"lbm_writes_lt_1ms":832,"mutex_wait_us":1564,"peak_mem_usage":98903847,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":78,"threads_started":1,"update_count":3945}
I20260812 06:20:34.647161 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=19.056125
I20260812 06:20:34.714150 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.067s	user 0.040s	sys 0.020s Metrics: {"bytes_written":21373825,"delete_count":0,"lbm_write_time_us":29530,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":523,"reinsert_count":0,"update_count":2605}
I20260812 06:20:34.714672 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=6.157687
I20260812 06:20:34.738237 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.023s	user 0.014s	sys 0.005s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":9384,"lbm_writes_lt_1ms":193,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":950}
I20260812 06:20:34.738857 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling MajorDeltaCompactionOp(b702b94ab960437dacb0dafe0416ef5a): perf score=1.000000
I20260812 06:20:34.930465 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: MajorDeltaCompactionOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.191s	user 0.140s	sys 0.046s Metrics: {"cfile_cache_miss":743,"cfile_cache_miss_bytes":33430783,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":755,"lbm_read_time_us":13969,"lbm_reads_lt_1ms":779,"lbm_write_time_us":40101,"lbm_writes_lt_1ms":754,"mutex_wait_us":23,"peak_mem_usage":88420429,"reinsert_count":0,"spinlock_wait_cycles":12288,"update_count":3555}
I20260812 06:20:34.931185 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=18.063937
I20260812 06:20:34.987360 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.056s	user 0.033s	sys 0.021s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":24557,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:34.987972 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=2.188937
I20260812 06:20:35.009938 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.022s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6935,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:35.010561 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling MajorDeltaCompactionOp(b702b94ab960437dacb0dafe0416ef5a): perf score=1.000000
I20260812 06:20:35.172674 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: MajorDeltaCompactionOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.162s	user 0.121s	sys 0.041s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1092,"lbm_read_time_us":11388,"lbm_reads_lt_1ms":664,"lbm_write_time_us":34237,"lbm_writes_lt_1ms":643,"mutex_wait_us":315,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":19456,"update_count":3000}
I20260812 06:20:35.173923 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=14.095187
I20260812 06:20:35.225402 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.051s	user 0.022s	sys 0.026s Metrics: {"bytes_written":16409907,"delete_count":0,"lbm_write_time_us":22473,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:35.225983 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=2.188937
I20260812 06:20:35.242766 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.017s	user 0.013s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6580,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:35.243358 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling MajorDeltaCompactionOp(b702b94ab960437dacb0dafe0416ef5a): perf score=1.000000
I20260812 06:20:35.390483 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: MajorDeltaCompactionOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.147s	user 0.126s	sys 0.020s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774694,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":809,"lbm_read_time_us":9424,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27417,"lbm_writes_lt_1ms":543,"mutex_wait_us":56,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14336,"update_count":2500}
I20260812 06:20:35.391477 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=12.110812
I20260812 06:20:35.439213 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.048s	user 0.029s	sys 0.016s Metrics: {"bytes_written":13825382,"delete_count":0,"lbm_write_time_us":20154,"lbm_writes_lt_1ms":340,"reinsert_count":0,"update_count":1685}
I20260812 06:20:35.439745 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=1.196750
I20260812 06:20:35.463899 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.024s	user 0.005s	sys 0.004s Metrics: {"bytes_written":2994984,"delete_count":0,"lbm_write_time_us":3726,"lbm_writes_lt_1ms":76,"reinsert_count":0,"update_count":365}
I20260812 06:20:35.464478 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=2.188937
I20260812 06:20:35.474717 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.010s	user 0.002s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3792,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:35.475265 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling MajorDeltaCompactionOp(b702b94ab960437dacb0dafe0416ef5a): perf score=1.000000
I20260812 06:20:35.657076 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: MajorDeltaCompactionOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.182s	user 0.105s	sys 0.070s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774771,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":241,"lbm_read_time_us":11924,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32111,"lbm_writes_lt_1ms":543,"mutex_wait_us":33,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":2500}
I20260812 06:20:35.657696 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=14.095187
I20260812 06:20:35.726613 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.069s	user 0.045s	sys 0.018s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":29584,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:35.727159 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=2.188937
I20260812 06:20:35.739288 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4399,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:35.740028 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushMRSOp(b702b94ab960437dacb0dafe0416ef5a): perf score=1.000000
I20260812 06:20:35.773330 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushMRSOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.033s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":252,"dirs.run_wall_time_us":1633,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1677,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:35.774106 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling LogGCOp(b702b94ab960437dacb0dafe0416ef5a): free 120100590 bytes of WAL
I20260812 06:20:35.774418 28688 log_reader.cc:385] T b702b94ab960437dacb0dafe0416ef5a: removed 12 log segments from log reader
I20260812 06:20:35.774477 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000028 (ops 133-136)
I20260812 06:20:35.774525 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000029 (ops 137-141)
I20260812 06:20:35.774562 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000030 (ops 142-146)
I20260812 06:20:35.774592 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000031 (ops 147-151)
I20260812 06:20:35.774618 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000032 (ops 152-156)
I20260812 06:20:35.774648 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000033 (ops 157-160)
I20260812 06:20:35.774682 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000034 (ops 161-165)
I20260812 06:20:35.774716 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000035 (ops 166-170)
I20260812 06:20:35.774745 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000036 (ops 171-175)
I20260812 06:20:35.774772 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000037 (ops 176-180)
I20260812 06:20:35.774801 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000038 (ops 181-184)
I20260812 06:20:35.774827 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000039 (ops 185-189)
I20260812 06:20:35.807217 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: LogGCOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.033s	user 0.001s	sys 0.031s Metrics: {}
I20260812 06:20:35.807659 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling UndoDeltaBlockGCOp(b702b94ab960437dacb0dafe0416ef5a): 472 bytes on disk
I20260812 06:20:35.808110 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: UndoDeltaBlockGCOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:20:35.808671 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=2.188937
I20260812 06:20:35.834132 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.025s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4430,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:35.834708 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling LogGCOp(b702b94ab960437dacb0dafe0416ef5a): free 12017954 bytes of WAL
I20260812 06:20:35.834965 28688 log_reader.cc:385] T b702b94ab960437dacb0dafe0416ef5a: removed 1 log segments from log reader
I20260812 06:20:35.835031 28688 log.cc:1079] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: Deleting log segment in path: /tmp/dist-test-taskBTchuV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625054964-28348-0/minicluster-data/ts-0-root/wals/b702b94ab960437dacb0dafe0416ef5a/wal-000000040 (ops 190-194)
I20260812 06:20:35.838169 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: LogGCOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:20:35.838668 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=2.188937
I20260812 06:20:35.856637 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.018s	user 0.005s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6647,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:35.857286 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling MajorDeltaCompactionOp(b702b94ab960437dacb0dafe0416ef5a): perf score=1.000000
I20260812 06:20:35.995884 28348 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.023s	user 1.860s	sys 0.142s
I20260812 06:20:36.091804 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: MajorDeltaCompactionOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.234s	user 0.142s	sys 0.092s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979748,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":715,"lbm_read_time_us":16847,"lbm_reads_lt_1ms":770,"lbm_write_time_us":42531,"lbm_writes_lt_1ms":743,"mutex_wait_us":26,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":24448,"thread_start_us":77,"threads_started":1,"update_count":3500}
I20260812 06:20:36.092610 28756 maintenance_manager.cc:419] P 8c77724efb5745b9a76fc09e7b9d2061: Scheduling FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a): perf score=10.126437
I20260812 06:20:36.101378 28348 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.105s	user 0.001s	sys 0.000s
I20260812 06:20:36.101948 28348 tablet_server.cc:179] TabletServer@127.27.175.1:0 shutting down...
I20260812 06:20:36.126040 28688 maintenance_manager.cc:643] P 8c77724efb5745b9a76fc09e7b9d2061: FlushDeltaMemStoresOp(b702b94ab960437dacb0dafe0416ef5a) complete. Timing: real 0.033s	user 0.013s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14182,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:36.126883 28348 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:36.127215 28348 tablet_replica.cc:333] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061: stopping tablet replica
I20260812 06:20:36.127377 28348 raft_consensus.cc:2243] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:36.127576 28348 raft_consensus.cc:2272] T b702b94ab960437dacb0dafe0416ef5a P 8c77724efb5745b9a76fc09e7b9d2061 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:36.131179 28348 tablet_server.cc:196] TabletServer@127.27.175.1:0 shutdown complete.
I20260812 06:20:36.150995 28348 master.cc:562] Master@127.27.175.62:33183 shutting down...
I20260812 06:20:36.154678 28348 raft_consensus.cc:2243] T 00000000000000000000000000000000 P e089cb2ed6e743a7a022828e4b044f80 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:36.154889 28348 raft_consensus.cc:2272] T 00000000000000000000000000000000 P e089cb2ed6e743a7a022828e4b044f80 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:36.154979 28348 tablet_replica.cc:333] T 00000000000000000000000000000000 P e089cb2ed6e743a7a022828e4b044f80: stopping tablet replica
I20260812 06:20:36.167632 28348 master.cc:584] Master@127.27.175.62:33183 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5533 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11193 ms total)

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