[==========] 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:18:06.472496 17010 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.16.156.190:46801
I20260812 06:18:06.473466 17010 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:18:06.474047 17010 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:06.480074 17020 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:18:06.480074 17017 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:18:06.480134 17010 server_base.cc:1061] running on GCE node
W20260812 06:18:06.480422 17016 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:06.480875 17010 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:06.481009 17010 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:18:06.481053 17010 hybrid_clock.cc:648] HybridClock initialized: now 1786515486481050 us; error 0 us; skew 500 ppm
I20260812 06:18:06.482700 17010 webserver.cc:533] Webserver started at http://127.16.156.190:45625/ using document root <none> and password file <none>
I20260812 06:18:06.483276 17010 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:06.483361 17010 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:06.483587 17010 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:06.485128 17010 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/master-0-root/instance:
uuid: "356951a9ec8d4802891934dd536df240"
format_stamp: "Formatted at 2026-08-12 06:18:06 on dist-test-slave-92m1"
I20260812 06:18:06.488389 17010 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:18:06.490350 17031 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:18:06.491371 17010 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:18:06.491488 17010 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/master-0-root
uuid: "356951a9ec8d4802891934dd536df240"
format_stamp: "Formatted at 2026-08-12 06:18:06 on dist-test-slave-92m1"
I20260812 06:18:06.491593 17010 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-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:18:06.513247 17010 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:06.513965 17010 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:18:06.514168 17010 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:06.522734 17010 rpc_server.cc:307] RPC server started. Bound to: 127.16.156.190:46801
I20260812 06:18:06.522749 17130 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.16.156.190:46801 every 8 connection(s)
I20260812 06:18:06.525115 17132 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:18:06.530397 17132 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 356951a9ec8d4802891934dd536df240: Bootstrap starting.
I20260812 06:18:06.532733 17132 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 356951a9ec8d4802891934dd536df240: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:06.533634 17132 log.cc:826] T 00000000000000000000000000000000 P 356951a9ec8d4802891934dd536df240: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:06.535303 17132 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 356951a9ec8d4802891934dd536df240: No bootstrap required, opened a new log
I20260812 06:18:06.537981 17132 raft_consensus.cc:359] T 00000000000000000000000000000000 P 356951a9ec8d4802891934dd536df240 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "356951a9ec8d4802891934dd536df240" member_type: VOTER }
I20260812 06:18:06.538144 17132 raft_consensus.cc:385] T 00000000000000000000000000000000 P 356951a9ec8d4802891934dd536df240 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:06.538230 17132 raft_consensus.cc:740] T 00000000000000000000000000000000 P 356951a9ec8d4802891934dd536df240 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 356951a9ec8d4802891934dd536df240, State: Initialized, Role: FOLLOWER
I20260812 06:18:06.538866 17132 consensus_queue.cc:260] T 00000000000000000000000000000000 P 356951a9ec8d4802891934dd536df240 [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: "356951a9ec8d4802891934dd536df240" member_type: VOTER }
I20260812 06:18:06.539004 17132 raft_consensus.cc:399] T 00000000000000000000000000000000 P 356951a9ec8d4802891934dd536df240 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:06.539130 17132 raft_consensus.cc:493] T 00000000000000000000000000000000 P 356951a9ec8d4802891934dd536df240 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:06.539294 17132 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 356951a9ec8d4802891934dd536df240 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:06.539994 17132 raft_consensus.cc:515] T 00000000000000000000000000000000 P 356951a9ec8d4802891934dd536df240 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "356951a9ec8d4802891934dd536df240" member_type: VOTER }
I20260812 06:18:06.540457 17132 leader_election.cc:304] T 00000000000000000000000000000000 P 356951a9ec8d4802891934dd536df240 [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: 356951a9ec8d4802891934dd536df240; no voters: 
I20260812 06:18:06.540722 17132 leader_election.cc:290] T 00000000000000000000000000000000 P 356951a9ec8d4802891934dd536df240 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:06.540867 17137 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 356951a9ec8d4802891934dd536df240 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:06.541154 17137 raft_consensus.cc:697] T 00000000000000000000000000000000 P 356951a9ec8d4802891934dd536df240 [term 1 LEADER]: Becoming Leader. State: Replica: 356951a9ec8d4802891934dd536df240, State: Running, Role: LEADER
I20260812 06:18:06.541517 17137 consensus_queue.cc:237] T 00000000000000000000000000000000 P 356951a9ec8d4802891934dd536df240 [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: "356951a9ec8d4802891934dd536df240" member_type: VOTER }
I20260812 06:18:06.541715 17132 sys_catalog.cc:565] T 00000000000000000000000000000000 P 356951a9ec8d4802891934dd536df240 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:06.543443 17139 sys_catalog.cc:455] T 00000000000000000000000000000000 P 356951a9ec8d4802891934dd536df240 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "356951a9ec8d4802891934dd536df240" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "356951a9ec8d4802891934dd536df240" member_type: VOTER } }
I20260812 06:18:06.543466 17142 sys_catalog.cc:455] T 00000000000000000000000000000000 P 356951a9ec8d4802891934dd536df240 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 356951a9ec8d4802891934dd536df240. Latest consensus state: current_term: 1 leader_uuid: "356951a9ec8d4802891934dd536df240" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "356951a9ec8d4802891934dd536df240" member_type: VOTER } }
I20260812 06:18:06.543548 17139 sys_catalog.cc:458] T 00000000000000000000000000000000 P 356951a9ec8d4802891934dd536df240 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:06.543573 17142 sys_catalog.cc:458] T 00000000000000000000000000000000 P 356951a9ec8d4802891934dd536df240 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:06.543968 17153 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:06.544214 17010 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:06.546162 17153 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:06.550719 17153 catalog_manager.cc:1383] Generated new cluster ID: d4b409c3b0834e18a816ddacf76b0aa1
I20260812 06:18:06.550783 17153 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:06.559108 17153 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:06.560211 17153 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:06.574784 17153 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 356951a9ec8d4802891934dd536df240: Generated new TSK 0
I20260812 06:18:06.575564 17153 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:06.576915 17010 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:06.579499 17170 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:18:06.579607 17169 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:18:06.579742 17173 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:18:06.579756 17010 server_base.cc:1061] running on GCE node
I20260812 06:18:06.580062 17010 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:06.580107 17010 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:18:06.580123 17010 hybrid_clock.cc:648] HybridClock initialized: now 1786515486580123 us; error 0 us; skew 500 ppm
I20260812 06:18:06.581094 17010 webserver.cc:533] Webserver started at http://127.16.156.129:34683/ using document root <none> and password file <none>
I20260812 06:18:06.581270 17010 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:06.581329 17010 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:06.581427 17010 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:06.581840 17010 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root/instance:
uuid: "2a39c621a2f749c0afb1b082d76adb08"
format_stamp: "Formatted at 2026-08-12 06:18:06 on dist-test-slave-92m1"
I20260812 06:18:06.583377 17010 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:06.584558 17179 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:18:06.584828 17010 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:06.584915 17010 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root
uuid: "2a39c621a2f749c0afb1b082d76adb08"
format_stamp: "Formatted at 2026-08-12 06:18:06 on dist-test-slave-92m1"
I20260812 06:18:06.585037 17010 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-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:18:06.613335 17010 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:06.613807 17010 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:06.614277 17010 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:06.615244 17010 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:06.615327 17010 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:06.615404 17010 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:06.615442 17010 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:06.622135 17010 rpc_server.cc:307] RPC server started. Bound to: 127.16.156.129:40043
I20260812 06:18:06.622157 17276 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.16.156.129:40043 every 8 connection(s)
I20260812 06:18:06.637243 17277 heartbeater.cc:344] Connected to a master server at 127.16.156.190:46801
I20260812 06:18:06.637544 17277 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:06.638054 17277 heartbeater.cc:507] Master 127.16.156.190:46801 requested a full tablet report, sending...
I20260812 06:18:06.639592 17064 ts_manager.cc:194] Registered new tserver with Master: 2a39c621a2f749c0afb1b082d76adb08 (127.16.156.129:40043)
I20260812 06:18:06.639719 17010 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.016939091s
I20260812 06:18:06.640916 17064 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:54030
I20260812 06:18:06.649214 17064 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:54036:
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:18:06.663290 17221 tablet_service.cc:1511] Processing CreateTablet for tablet 1afb50e339054703ae2aa73f02793312 (DEFAULT_TABLE table=heavy-update-compaction-test [id=cec971c3b56c4ae689b8be64a9b62483]), partition=
I20260812 06:18:06.663734 17221 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 1afb50e339054703ae2aa73f02793312. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:06.666543 17298 tablet_bootstrap.cc:492] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Bootstrap starting.
I20260812 06:18:06.667770 17298 tablet_bootstrap.cc:654] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:06.669019 17298 tablet_bootstrap.cc:492] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: No bootstrap required, opened a new log
I20260812 06:18:06.669134 17298 ts_tablet_manager.cc:1403] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:18:06.669618 17298 raft_consensus.cc:359] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2a39c621a2f749c0afb1b082d76adb08" member_type: VOTER last_known_addr { host: "127.16.156.129" port: 40043 } }
I20260812 06:18:06.669723 17298 raft_consensus.cc:385] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:06.669749 17298 raft_consensus.cc:740] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2a39c621a2f749c0afb1b082d76adb08, State: Initialized, Role: FOLLOWER
I20260812 06:18:06.669943 17298 consensus_queue.cc:260] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08 [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: "2a39c621a2f749c0afb1b082d76adb08" member_type: VOTER last_known_addr { host: "127.16.156.129" port: 40043 } }
I20260812 06:18:06.670044 17298 raft_consensus.cc:399] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:06.670099 17298 raft_consensus.cc:493] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:06.670162 17298 raft_consensus.cc:3060] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:06.671310 17298 raft_consensus.cc:515] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2a39c621a2f749c0afb1b082d76adb08" member_type: VOTER last_known_addr { host: "127.16.156.129" port: 40043 } }
I20260812 06:18:06.671466 17298 leader_election.cc:304] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08 [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: 2a39c621a2f749c0afb1b082d76adb08; no voters: 
I20260812 06:18:06.671737 17298 leader_election.cc:290] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:06.671849 17303 raft_consensus.cc:2804] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:06.672047 17303 raft_consensus.cc:697] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08 [term 1 LEADER]: Becoming Leader. State: Replica: 2a39c621a2f749c0afb1b082d76adb08, State: Running, Role: LEADER
I20260812 06:18:06.672176 17298 ts_tablet_manager.cc:1434] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Time spent starting tablet: real 0.003s	user 0.001s	sys 0.003s
I20260812 06:18:06.672271 17303 consensus_queue.cc:237] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08 [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: "2a39c621a2f749c0afb1b082d76adb08" member_type: VOTER last_known_addr { host: "127.16.156.129" port: 40043 } }
I20260812 06:18:06.672329 17277 heartbeater.cc:499] Master 127.16.156.190:46801 was elected leader, sending a full tablet report...
I20260812 06:18:06.675050 17064 catalog_manager.cc:5719] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08 reported cstate change: term changed from 0 to 1, leader changed from <none> to 2a39c621a2f749c0afb1b082d76adb08 (127.16.156.129). New cstate: current_term: 1 leader_uuid: "2a39c621a2f749c0afb1b082d76adb08" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2a39c621a2f749c0afb1b082d76adb08" member_type: VOTER last_known_addr { host: "127.16.156.129" port: 40043 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:06.748993 17010 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.065s	user 0.031s	sys 0.003s
I20260812 06:18:06.873246 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushMRSOp(1afb50e339054703ae2aa73f02793312): perf score=15.086190
I20260812 06:18:07.043023 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushMRSOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.169s	user 0.127s	sys 0.040s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":212,"delete_count":0,"dirs.queue_time_us":52,"dirs.run_cpu_time_us":291,"dirs.run_wall_time_us":1026,"drs_written":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4,"lbm_write_time_us":43738,"lbm_writes_lt_1ms":667,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":182016,"thread_start_us":142,"threads_started":1,"update_count":1500}
I20260812 06:18:07.044531 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling LogGCOp(1afb50e339054703ae2aa73f02793312): free 20743880 bytes of WAL
I20260812 06:18:07.045343 17186 log_reader.cc:385] T 1afb50e339054703ae2aa73f02793312: removed 2 log segments from log reader
I20260812 06:18:07.045543 17186 log.cc:1079] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/1afb50e339054703ae2aa73f02793312/wal-000000001 (ops 1-6)
I20260812 06:18:07.045722 17186 log.cc:1079] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/1afb50e339054703ae2aa73f02793312/wal-000000002 (ops 7-11)
I20260812 06:18:07.052138 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: LogGCOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.007s	user 0.000s	sys 0.006s Metrics: {}
I20260812 06:18:07.052764 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling UndoDeltaBlockGCOp(1afb50e339054703ae2aa73f02793312): 12719216 bytes on disk
I20260812 06:18:07.053705 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: UndoDeltaBlockGCOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":89,"lbm_reads_lt_1ms":4}
I20260812 06:18:07.054315 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=2.188937
I20260812 06:18:07.079499 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.025s	user 0.004s	sys 0.007s Metrics: {"bytes_written":3979584,"delete_count":0,"lbm_write_time_us":4602,"lbm_writes_lt_1ms":100,"reinsert_count":0,"update_count":485}
I20260812 06:18:07.080034 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=2.188937
I20260812 06:18:07.090794 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3815484,"delete_count":0,"lbm_write_time_us":4293,"lbm_writes_lt_1ms":96,"reinsert_count":0,"update_count":465}
I20260812 06:18:07.091246 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling MajorDeltaCompactionOp(1afb50e339054703ae2aa73f02793312): perf score=1.000000
I20260812 06:18:07.249568 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: MajorDeltaCompactionOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.158s	user 0.128s	sys 0.029s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24364558,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":596,"lbm_read_time_us":10972,"lbm_reads_lt_1ms":559,"lbm_write_time_us":30962,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"thread_start_us":310,"threads_started":5,"update_count":2450}
I20260812 06:18:07.250173 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=10.126437
I20260812 06:18:07.292299 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.042s	user 0.022s	sys 0.012s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15361,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:07.292820 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=2.188937
I20260812 06:18:07.303282 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4073,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:07.303673 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling MajorDeltaCompactionOp(1afb50e339054703ae2aa73f02793312): perf score=1.000000
I20260812 06:18:07.432241 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: MajorDeltaCompactionOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.128s	user 0.116s	sys 0.012s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1140,"lbm_read_time_us":8367,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25982,"lbm_writes_lt_1ms":443,"mutex_wait_us":510,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14464,"update_count":2000}
I20260812 06:18:07.432849 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=10.126437
I20260812 06:18:07.468354 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.035s	user 0.023s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14048,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:07.468894 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=2.188937
I20260812 06:18:07.479121 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4043,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:07.479558 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling MajorDeltaCompactionOp(1afb50e339054703ae2aa73f02793312): perf score=1.000000
I20260812 06:18:07.599586 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: MajorDeltaCompactionOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.120s	user 0.088s	sys 0.032s 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":117,"lbm_read_time_us":8634,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24831,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:18:07.600195 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=10.126437
I20260812 06:18:07.649175 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.049s	user 0.024s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15007,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:07.649792 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=2.188937
I20260812 06:18:07.665517 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6454,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:07.665953 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling MajorDeltaCompactionOp(1afb50e339054703ae2aa73f02793312): perf score=1.000000
I20260812 06:18:07.823621 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: MajorDeltaCompactionOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.157s	user 0.102s	sys 0.048s 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":1172,"lbm_read_time_us":10808,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25456,"lbm_writes_lt_1ms":443,"mutex_wait_us":428,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":2000}
I20260812 06:18:07.824333 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=10.126437
I20260812 06:18:07.873404 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.049s	user 0.029s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18596,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:07.873999 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=2.188937
I20260812 06:18:07.886711 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4733,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:07.887282 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling MajorDeltaCompactionOp(1afb50e339054703ae2aa73f02793312): perf score=1.000000
I20260812 06:18:08.019429 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: MajorDeltaCompactionOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.132s	user 0.115s	sys 0.017s 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":999,"lbm_read_time_us":10329,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23525,"lbm_writes_lt_1ms":443,"mutex_wait_us":257,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8832,"update_count":2000}
I20260812 06:18:08.020066 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=10.126437
I20260812 06:18:08.068253 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.048s	user 0.022s	sys 0.024s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":23833,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:18:08.068889 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=2.188937
I20260812 06:18:08.086311 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.017s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5085,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:08.086774 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling MajorDeltaCompactionOp(1afb50e339054703ae2aa73f02793312): perf score=1.000000
I20260812 06:18:08.224164 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: MajorDeltaCompactionOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.137s	user 0.105s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672275,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":757,"lbm_read_time_us":7186,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27276,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:18:08.224771 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=11.118625
I20260812 06:18:08.265580 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.041s	user 0.018s	sys 0.020s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":18459,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:08.266106 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=2.188937
I20260812 06:18:08.281066 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5943,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:08.281826 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushMRSOp(1afb50e339054703ae2aa73f02793312): perf score=1.000000
I20260812 06:18:08.317413 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushMRSOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.035s	user 0.033s	sys 0.001s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":233,"dirs.run_wall_time_us":1113,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2000,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:08.318284 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling LogGCOp(1afb50e339054703ae2aa73f02793312): free 112692376 bytes of WAL
I20260812 06:18:08.318554 17186 log_reader.cc:385] T 1afb50e339054703ae2aa73f02793312: removed 11 log segments from log reader
I20260812 06:18:08.318619 17186 log.cc:1079] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/1afb50e339054703ae2aa73f02793312/wal-000000003 (ops 12-16)
I20260812 06:18:08.318656 17186 log.cc:1079] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/1afb50e339054703ae2aa73f02793312/wal-000000004 (ops 17-21)
I20260812 06:18:08.318689 17186 log.cc:1079] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/1afb50e339054703ae2aa73f02793312/wal-000000005 (ops 22-26)
I20260812 06:18:08.318714 17186 log.cc:1079] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/1afb50e339054703ae2aa73f02793312/wal-000000006 (ops 27-31)
I20260812 06:18:08.318748 17186 log.cc:1079] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/1afb50e339054703ae2aa73f02793312/wal-000000007 (ops 32-36)
I20260812 06:18:08.318780 17186 log.cc:1079] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/1afb50e339054703ae2aa73f02793312/wal-000000008 (ops 37-41)
I20260812 06:18:08.318810 17186 log.cc:1079] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/1afb50e339054703ae2aa73f02793312/wal-000000009 (ops 42-46)
I20260812 06:18:08.318840 17186 log.cc:1079] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/1afb50e339054703ae2aa73f02793312/wal-000000010 (ops 47-51)
I20260812 06:18:08.318871 17186 log.cc:1079] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/1afb50e339054703ae2aa73f02793312/wal-000000011 (ops 52-56)
I20260812 06:18:08.318905 17186 log.cc:1079] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/1afb50e339054703ae2aa73f02793312/wal-000000012 (ops 57-61)
I20260812 06:18:08.318938 17186 log.cc:1079] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/1afb50e339054703ae2aa73f02793312/wal-000000013 (ops 62-66)
I20260812 06:18:08.347236 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: LogGCOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.029s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:18:08.347735 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=2.188937
I20260812 06:18:08.372009 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.024s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4925,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:08.372529 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling UndoDeltaBlockGCOp(1afb50e339054703ae2aa73f02793312): 447 bytes on disk
I20260812 06:18:08.373044 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: UndoDeltaBlockGCOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:18:08.373528 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=2.188937
I20260812 06:18:08.387933 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.014s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4749,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:08.388399 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling MajorDeltaCompactionOp(1afb50e339054703ae2aa73f02793312): perf score=1.000000
I20260812 06:18:08.559248 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: MajorDeltaCompactionOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.171s	user 0.132s	sys 0.033s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877330,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":281,"lbm_read_time_us":12273,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33529,"lbm_writes_lt_1ms":643,"mutex_wait_us":2,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":75,"threads_started":1,"update_count":3000}
I20260812 06:18:08.559772 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=14.095187
I20260812 06:18:08.616633 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.056s	user 0.033s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22672,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:08.617117 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=2.188937
I20260812 06:18:08.628360 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4191,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:08.628793 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling MajorDeltaCompactionOp(1afb50e339054703ae2aa73f02793312): perf score=1.000000
I20260812 06:18:08.790540 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: MajorDeltaCompactionOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.162s	user 0.115s	sys 0.045s 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":933,"lbm_read_time_us":10320,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33025,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":90368,"update_count":2500}
I20260812 06:18:08.791550 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=14.095187
I20260812 06:18:08.871838 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.080s	user 0.033s	sys 0.033s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":32147,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:18:08.872377 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=2.188937
I20260812 06:18:08.884049 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4356,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:08.884852 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling MajorDeltaCompactionOp(1afb50e339054703ae2aa73f02793312): perf score=1.000000
I20260812 06:18:09.055622 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: MajorDeltaCompactionOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.171s	user 0.138s	sys 0.032s 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":1106,"lbm_read_time_us":12698,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30108,"lbm_writes_lt_1ms":543,"mutex_wait_us":334,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18944,"update_count":2500}
I20260812 06:18:09.056397 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=14.095187
I20260812 06:18:09.115862 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.059s	user 0.026s	sys 0.032s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":26940,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:09.116474 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=2.188937
I20260812 06:18:09.132725 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.016s	user 0.009s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5919,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:09.133241 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling MajorDeltaCompactionOp(1afb50e339054703ae2aa73f02793312): perf score=1.000000
I20260812 06:18:09.307438 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: MajorDeltaCompactionOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.174s	user 0.120s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":357,"lbm_read_time_us":11517,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32324,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9344,"update_count":2500}
I20260812 06:18:09.308163 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=14.095187
I20260812 06:18:09.370438 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.062s	user 0.023s	sys 0.036s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22658,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:09.371047 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=2.188937
I20260812 06:18:09.381767 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4274,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:09.382185 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling MajorDeltaCompactionOp(1afb50e339054703ae2aa73f02793312): perf score=1.000000
I20260812 06:18:09.556772 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: MajorDeltaCompactionOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.174s	user 0.121s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":262,"lbm_read_time_us":12406,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29760,"lbm_writes_lt_1ms":543,"mutex_wait_us":66,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2500}
I20260812 06:18:09.557544 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=11.118625
I20260812 06:18:09.604223 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.046s	user 0.025s	sys 0.020s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":19375,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:18:09.604781 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=2.188937
I20260812 06:18:09.630658 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.026s	user 0.006s	sys 0.010s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4276,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:09.631183 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=2.188937
I20260812 06:18:09.642223 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4321,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:09.642706 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling MajorDeltaCompactionOp(1afb50e339054703ae2aa73f02793312): perf score=1.000000
I20260812 06:18:09.818358 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: MajorDeltaCompactionOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.175s	user 0.120s	sys 0.056s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774798,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":315,"lbm_read_time_us":12319,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30284,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15360,"update_count":2500}
I20260812 06:18:09.819142 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=10.126437
I20260812 06:18:09.864509 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.045s	user 0.019s	sys 0.024s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":19845,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:09.865207 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=2.188937
I20260812 06:18:09.883503 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.018s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5303,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:09.883994 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushMRSOp(1afb50e339054703ae2aa73f02793312): perf score=1.000000
I20260812 06:18:09.925549 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushMRSOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.041s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":235,"dirs.run_wall_time_us":1685,"drs_written":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1699,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:09.926424 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=3.181125
I20260812 06:18:09.952395 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.026s	user 0.014s	sys 0.004s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":6943,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:09.953105 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling LogGCOp(1afb50e339054703ae2aa73f02793312): free 132571311 bytes of WAL
I20260812 06:18:09.953377 17186 log_reader.cc:385] T 1afb50e339054703ae2aa73f02793312: removed 13 log segments from log reader
I20260812 06:18:09.953415 17186 log.cc:1079] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/1afb50e339054703ae2aa73f02793312/wal-000000014 (ops 67-70)
I20260812 06:18:09.953471 17186 log.cc:1079] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/1afb50e339054703ae2aa73f02793312/wal-000000015 (ops 71-75)
I20260812 06:18:09.953516 17186 log.cc:1079] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/1afb50e339054703ae2aa73f02793312/wal-000000016 (ops 76-80)
I20260812 06:18:09.953539 17186 log.cc:1079] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/1afb50e339054703ae2aa73f02793312/wal-000000017 (ops 81-85)
I20260812 06:18:09.953580 17186 log.cc:1079] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/1afb50e339054703ae2aa73f02793312/wal-000000018 (ops 86-90)
I20260812 06:18:09.953619 17186 log.cc:1079] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/1afb50e339054703ae2aa73f02793312/wal-000000019 (ops 91-94)
I20260812 06:18:09.953657 17186 log.cc:1079] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/1afb50e339054703ae2aa73f02793312/wal-000000020 (ops 95-99)
I20260812 06:18:09.953697 17186 log.cc:1079] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/1afb50e339054703ae2aa73f02793312/wal-000000021 (ops 100-104)
I20260812 06:18:09.953735 17186 log.cc:1079] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/1afb50e339054703ae2aa73f02793312/wal-000000022 (ops 105-109)
I20260812 06:18:09.953774 17186 log.cc:1079] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/1afb50e339054703ae2aa73f02793312/wal-000000023 (ops 110-114)
I20260812 06:18:09.953812 17186 log.cc:1079] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/1afb50e339054703ae2aa73f02793312/wal-000000024 (ops 115-119)
I20260812 06:18:09.953851 17186 log.cc:1079] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/1afb50e339054703ae2aa73f02793312/wal-000000025 (ops 120-124)
I20260812 06:18:09.953890 17186 log.cc:1079] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/1afb50e339054703ae2aa73f02793312/wal-000000026 (ops 125-129)
I20260812 06:18:09.980556 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: LogGCOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:18:09.981048 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling UndoDeltaBlockGCOp(1afb50e339054703ae2aa73f02793312): 491 bytes on disk
I20260812 06:18:09.981478 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: UndoDeltaBlockGCOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:18:09.982066 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=2.188937
I20260812 06:18:10.003857 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.022s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5686,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:10.004317 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=2.188937
I20260812 06:18:10.014351 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3935,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:10.014933 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling MajorDeltaCompactionOp(1afb50e339054703ae2aa73f02793312): perf score=1.000000
I20260812 06:18:10.254935 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: MajorDeltaCompactionOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.240s	user 0.156s	sys 0.080s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979860,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":3954,"lbm_read_time_us":15892,"lbm_reads_lt_1ms":775,"lbm_write_time_us":42836,"lbm_writes_lt_1ms":743,"mutex_wait_us":44,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":15744,"thread_start_us":115,"threads_started":1,"update_count":3500}
I20260812 06:18:10.255684 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=14.095187
I20260812 06:18:10.300114 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.044s	user 0.025s	sys 0.018s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19808,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:10.302548 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=2.188937
I20260812 06:18:10.322551 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.020s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6707,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:10.323055 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling MajorDeltaCompactionOp(1afb50e339054703ae2aa73f02793312): perf score=1.000000
I20260812 06:18:10.493955 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: MajorDeltaCompactionOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.171s	user 0.113s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2072,"lbm_read_time_us":12258,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28495,"lbm_writes_lt_1ms":543,"mutex_wait_us":3,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:10.494647 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=15.087375
I20260812 06:18:10.547761 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.053s	user 0.033s	sys 0.018s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":19140,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:18:10.548456 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=2.188937
I20260812 06:18:10.560451 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4447,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:10.560938 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=2.188937
I20260812 06:18:10.571615 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4290,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:10.572132 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling MajorDeltaCompactionOp(1afb50e339054703ae2aa73f02793312): perf score=1.000000
I20260812 06:18:10.793294 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: MajorDeltaCompactionOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.221s	user 0.148s	sys 0.073s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877207,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":139,"lbm_read_time_us":15506,"lbm_reads_lt_1ms":673,"lbm_write_time_us":38214,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:18:10.794121 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=14.095187
I20260812 06:18:10.848016 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.054s	user 0.033s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23146,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:10.848666 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=2.188937
I20260812 06:18:10.875420 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.027s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5336,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:10.875877 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=2.188937
I20260812 06:18:10.885977 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3814,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:10.886443 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling MajorDeltaCompactionOp(1afb50e339054703ae2aa73f02793312): perf score=1.000000
I20260812 06:18:11.088207 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: MajorDeltaCompactionOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.202s	user 0.127s	sys 0.063s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877219,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":948,"lbm_read_time_us":13495,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33320,"lbm_writes_lt_1ms":643,"mutex_wait_us":433,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:18:11.089005 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=14.095187
I20260812 06:18:11.156528 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.067s	user 0.029s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":26007,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:11.157075 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling MajorDeltaCompactionOp(1afb50e339054703ae2aa73f02793312): perf score=1.000000
I20260812 06:18:11.316273 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: MajorDeltaCompactionOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.159s	user 0.111s	sys 0.036s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":190,"lbm_read_time_us":11855,"lbm_reads_lt_1ms":463,"lbm_write_time_us":24681,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":2000}
I20260812 06:18:11.316838 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=14.095187
I20260812 06:18:11.374225 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.057s	user 0.028s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23008,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:11.374800 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=2.188937
I20260812 06:18:11.385409 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4227,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.386078 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushMRSOp(1afb50e339054703ae2aa73f02793312): perf score=1.000000
I20260812 06:18:11.424026 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushMRSOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.038s	user 0.037s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":250,"dirs.run_wall_time_us":1431,"drs_written":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1711,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:11.424888 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling LogGCOp(1afb50e339054703ae2aa73f02793312): free 120100582 bytes of WAL
I20260812 06:18:11.425181 17186 log_reader.cc:385] T 1afb50e339054703ae2aa73f02793312: removed 12 log segments from log reader
I20260812 06:18:11.425251 17186 log.cc:1079] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/1afb50e339054703ae2aa73f02793312/wal-000000027 (ops 130-134)
I20260812 06:18:11.425290 17186 log.cc:1079] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/1afb50e339054703ae2aa73f02793312/wal-000000028 (ops 135-138)
I20260812 06:18:11.425321 17186 log.cc:1079] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/1afb50e339054703ae2aa73f02793312/wal-000000029 (ops 139-143)
I20260812 06:18:11.425350 17186 log.cc:1079] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/1afb50e339054703ae2aa73f02793312/wal-000000030 (ops 144-148)
I20260812 06:18:11.425384 17186 log.cc:1079] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/1afb50e339054703ae2aa73f02793312/wal-000000031 (ops 149-153)
I20260812 06:18:11.425414 17186 log.cc:1079] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/1afb50e339054703ae2aa73f02793312/wal-000000032 (ops 154-158)
I20260812 06:18:11.425446 17186 log.cc:1079] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/1afb50e339054703ae2aa73f02793312/wal-000000033 (ops 159-162)
I20260812 06:18:11.425482 17186 log.cc:1079] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/1afb50e339054703ae2aa73f02793312/wal-000000034 (ops 163-167)
I20260812 06:18:11.425519 17186 log.cc:1079] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/1afb50e339054703ae2aa73f02793312/wal-000000035 (ops 168-172)
I20260812 06:18:11.425556 17186 log.cc:1079] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/1afb50e339054703ae2aa73f02793312/wal-000000036 (ops 173-177)
I20260812 06:18:11.425588 17186 log.cc:1079] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/1afb50e339054703ae2aa73f02793312/wal-000000037 (ops 178-182)
I20260812 06:18:11.425619 17186 log.cc:1079] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/1afb50e339054703ae2aa73f02793312/wal-000000038 (ops 183-186)
I20260812 06:18:11.456353 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: LogGCOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.031s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:18:11.456769 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=2.188937
I20260812 06:18:11.482263 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.025s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5118,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.482790 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=2.188937
I20260812 06:18:11.494349 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4621,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.495126 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling MajorDeltaCompactionOp(1afb50e339054703ae2aa73f02793312): perf score=1.000000
I20260812 06:18:11.744163 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: MajorDeltaCompactionOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.249s	user 0.154s	sys 0.093s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979750,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1196,"lbm_read_time_us":16966,"lbm_reads_lt_1ms":774,"lbm_write_time_us":43505,"lbm_writes_lt_1ms":743,"mutex_wait_us":842,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":16000,"thread_start_us":89,"threads_started":1,"update_count":3500}
I20260812 06:18:11.745025 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=18.063937
I20260812 06:18:11.810900 17010 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.062s	user 1.844s	sys 0.170s
I20260812 06:18:11.814689 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.069s	user 0.031s	sys 0.028s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":28675,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:11.815141 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312): perf score=2.188937
I20260812 06:18:11.825464 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: FlushDeltaMemStoresOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4419,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.825958 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling UndoDeltaBlockGCOp(1afb50e339054703ae2aa73f02793312): 447 bytes on disk
I20260812 06:18:11.826365 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: UndoDeltaBlockGCOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:18:11.826844 17280 maintenance_manager.cc:419] P 2a39c621a2f749c0afb1b082d76adb08: Scheduling MajorDeltaCompactionOp(1afb50e339054703ae2aa73f02793312): perf score=1.000000
I20260812 06:18:11.882606 17010 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.071s	user 0.001s	sys 0.000s
I20260812 06:18:11.883376 17010 tablet_server.cc:179] TabletServer@127.16.156.129:0 shutting down...
I20260812 06:18:11.979384 17186 maintenance_manager.cc:643] P 2a39c621a2f749c0afb1b082d76adb08: MajorDeltaCompactionOp(1afb50e339054703ae2aa73f02793312) complete. Timing: real 0.152s	user 0.093s	sys 0.059s Metrics: {"cfile_cache_hit":257,"cfile_cache_hit_bytes":10505497,"cfile_cache_miss":375,"cfile_cache_miss_bytes":18371605,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":421,"lbm_read_time_us":8041,"lbm_reads_lt_1ms":407,"lbm_write_time_us":31075,"lbm_writes_lt_1ms":643,"mutex_wait_us":2,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":67968,"update_count":3000}
I20260812 06:18:11.980180 17010 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:11.980643 17010 tablet_replica.cc:333] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08: stopping tablet replica
I20260812 06:18:11.980898 17010 raft_consensus.cc:2243] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:11.981142 17010 raft_consensus.cc:2272] T 1afb50e339054703ae2aa73f02793312 P 2a39c621a2f749c0afb1b082d76adb08 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:11.996578 17010 tablet_server.cc:196] TabletServer@127.16.156.129:0 shutdown complete.
I20260812 06:18:12.034953 17010 master.cc:562] Master@127.16.156.190:46801 shutting down...
I20260812 06:18:12.039251 17010 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 356951a9ec8d4802891934dd536df240 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:12.039491 17010 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 356951a9ec8d4802891934dd536df240 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:12.039556 17010 tablet_replica.cc:333] T 00000000000000000000000000000000 P 356951a9ec8d4802891934dd536df240: stopping tablet replica
I20260812 06:18:12.052549 17010 master.cc:584] Master@127.16.156.190:46801 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5668 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:12.153432 17010 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.16.156.190:45711
I20260812 06:18:12.153846 17010 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:12.156438 17334 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:18:12.156580 17332 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:18:12.156533 17010 server_base.cc:1061] running on GCE node
W20260812 06:18:12.156456 17330 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:12.156862 17010 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:12.156906 17010 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:18:12.156921 17010 hybrid_clock.cc:648] HybridClock initialized: now 1786515492156922 us; error 0 us; skew 500 ppm
I20260812 06:18:12.157804 17010 webserver.cc:533] Webserver started at http://127.16.156.190:42171/ using document root <none> and password file <none>
I20260812 06:18:12.157994 17010 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:12.158080 17010 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:12.158186 17010 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:12.158600 17010 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/master-0-root/instance:
uuid: "76a6bc94b0cd4d3bba1c6365a6521845"
format_stamp: "Formatted at 2026-08-12 06:18:12 on dist-test-slave-92m1"
I20260812 06:18:12.160404 17010 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:18:12.161427 17344 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:18:12.161677 17010 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:12.161769 17010 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/master-0-root
uuid: "76a6bc94b0cd4d3bba1c6365a6521845"
format_stamp: "Formatted at 2026-08-12 06:18:12 on dist-test-slave-92m1"
I20260812 06:18:12.161857 17010 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-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:18:12.178371 17010 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:12.178762 17010 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:12.183396 17010 rpc_server.cc:307] RPC server started. Bound to: 127.16.156.190:45711
I20260812 06:18:12.185359 17429 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.16.156.190:45711 every 8 connection(s)
I20260812 06:18:12.188508 17430 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:18:12.190263 17430 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 76a6bc94b0cd4d3bba1c6365a6521845: Bootstrap starting.
I20260812 06:18:12.190973 17430 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 76a6bc94b0cd4d3bba1c6365a6521845: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:12.192022 17430 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 76a6bc94b0cd4d3bba1c6365a6521845: No bootstrap required, opened a new log
I20260812 06:18:12.192353 17430 raft_consensus.cc:359] T 00000000000000000000000000000000 P 76a6bc94b0cd4d3bba1c6365a6521845 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "76a6bc94b0cd4d3bba1c6365a6521845" member_type: VOTER }
I20260812 06:18:12.192433 17430 raft_consensus.cc:385] T 00000000000000000000000000000000 P 76a6bc94b0cd4d3bba1c6365a6521845 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:12.192456 17430 raft_consensus.cc:740] T 00000000000000000000000000000000 P 76a6bc94b0cd4d3bba1c6365a6521845 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 76a6bc94b0cd4d3bba1c6365a6521845, State: Initialized, Role: FOLLOWER
I20260812 06:18:12.192613 17430 consensus_queue.cc:260] T 00000000000000000000000000000000 P 76a6bc94b0cd4d3bba1c6365a6521845 [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: "76a6bc94b0cd4d3bba1c6365a6521845" member_type: VOTER }
I20260812 06:18:12.192703 17430 raft_consensus.cc:399] T 00000000000000000000000000000000 P 76a6bc94b0cd4d3bba1c6365a6521845 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:12.192727 17430 raft_consensus.cc:493] T 00000000000000000000000000000000 P 76a6bc94b0cd4d3bba1c6365a6521845 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:12.192764 17430 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 76a6bc94b0cd4d3bba1c6365a6521845 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:12.193382 17430 raft_consensus.cc:515] T 00000000000000000000000000000000 P 76a6bc94b0cd4d3bba1c6365a6521845 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "76a6bc94b0cd4d3bba1c6365a6521845" member_type: VOTER }
I20260812 06:18:12.193491 17430 leader_election.cc:304] T 00000000000000000000000000000000 P 76a6bc94b0cd4d3bba1c6365a6521845 [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: 76a6bc94b0cd4d3bba1c6365a6521845; no voters: 
I20260812 06:18:12.193632 17430 leader_election.cc:290] T 00000000000000000000000000000000 P 76a6bc94b0cd4d3bba1c6365a6521845 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:12.193784 17433 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 76a6bc94b0cd4d3bba1c6365a6521845 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:12.194022 17433 raft_consensus.cc:697] T 00000000000000000000000000000000 P 76a6bc94b0cd4d3bba1c6365a6521845 [term 1 LEADER]: Becoming Leader. State: Replica: 76a6bc94b0cd4d3bba1c6365a6521845, State: Running, Role: LEADER
I20260812 06:18:12.194111 17430 sys_catalog.cc:565] T 00000000000000000000000000000000 P 76a6bc94b0cd4d3bba1c6365a6521845 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:12.194154 17433 consensus_queue.cc:237] T 00000000000000000000000000000000 P 76a6bc94b0cd4d3bba1c6365a6521845 [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: "76a6bc94b0cd4d3bba1c6365a6521845" member_type: VOTER }
I20260812 06:18:12.194593 17434 sys_catalog.cc:455] T 00000000000000000000000000000000 P 76a6bc94b0cd4d3bba1c6365a6521845 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "76a6bc94b0cd4d3bba1c6365a6521845" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "76a6bc94b0cd4d3bba1c6365a6521845" member_type: VOTER } }
I20260812 06:18:12.194701 17434 sys_catalog.cc:458] T 00000000000000000000000000000000 P 76a6bc94b0cd4d3bba1c6365a6521845 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:12.194612 17435 sys_catalog.cc:455] T 00000000000000000000000000000000 P 76a6bc94b0cd4d3bba1c6365a6521845 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 76a6bc94b0cd4d3bba1c6365a6521845. Latest consensus state: current_term: 1 leader_uuid: "76a6bc94b0cd4d3bba1c6365a6521845" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "76a6bc94b0cd4d3bba1c6365a6521845" member_type: VOTER } }
I20260812 06:18:12.195006 17435 sys_catalog.cc:458] T 00000000000000000000000000000000 P 76a6bc94b0cd4d3bba1c6365a6521845 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:12.195034 17440 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:12.196156 17440 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:12.196362 17010 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:12.197969 17440 catalog_manager.cc:1383] Generated new cluster ID: 712e3d9d7c1549cc8bed585c42bccba0
I20260812 06:18:12.198040 17440 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:12.208057 17440 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:12.208675 17440 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:12.219802 17440 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 76a6bc94b0cd4d3bba1c6365a6521845: Generated new TSK 0
I20260812 06:18:12.220032 17440 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:12.228617 17010 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:12.230778 17463 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:18:12.230824 17464 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:18:12.230862 17010 server_base.cc:1061] running on GCE node
W20260812 06:18:12.230945 17467 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:18:12.231294 17010 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:12.231343 17010 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:18:12.231359 17010 hybrid_clock.cc:648] HybridClock initialized: now 1786515492231359 us; error 0 us; skew 500 ppm
I20260812 06:18:12.232224 17010 webserver.cc:533] Webserver started at http://127.16.156.129:33305/ using document root <none> and password file <none>
I20260812 06:18:12.232362 17010 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:12.232419 17010 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:12.232470 17010 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:12.232824 17010 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root/instance:
uuid: "cda2153ed93843dbacb43b5df11ad8ed"
format_stamp: "Formatted at 2026-08-12 06:18:12 on dist-test-slave-92m1"
I20260812 06:18:12.234392 17010 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:12.235338 17472 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:18:12.235620 17010 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:12.235713 17010 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root
uuid: "cda2153ed93843dbacb43b5df11ad8ed"
format_stamp: "Formatted at 2026-08-12 06:18:12 on dist-test-slave-92m1"
I20260812 06:18:12.235807 17010 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-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:18:12.247582 17010 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:12.247963 17010 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:12.248301 17010 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:12.248769 17010 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:12.248831 17010 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:12.248889 17010 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:12.248939 17010 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:12.253417 17010 rpc_server.cc:307] RPC server started. Bound to: 127.16.156.129:38725
I20260812 06:18:12.254915 17573 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.16.156.129:38725 every 8 connection(s)
I20260812 06:18:12.262717 17574 heartbeater.cc:344] Connected to a master server at 127.16.156.190:45711
I20260812 06:18:12.262853 17574 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:12.263115 17574 heartbeater.cc:507] Master 127.16.156.190:45711 requested a full tablet report, sending...
I20260812 06:18:12.263826 17368 ts_manager.cc:194] Registered new tserver with Master: cda2153ed93843dbacb43b5df11ad8ed (127.16.156.129:38725)
I20260812 06:18:12.264132 17010 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.009919809s
I20260812 06:18:12.264950 17368 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:55520
I20260812 06:18:12.272009 17368 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:55536:
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:18:12.280738 17524 tablet_service.cc:1511] Processing CreateTablet for tablet f3bc13089fa64684b2deb6640517192a (DEFAULT_TABLE table=heavy-update-compaction-test [id=2d364e20606f47bfb38744230a0aefdf]), partition=
I20260812 06:18:12.281025 17524 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet f3bc13089fa64684b2deb6640517192a. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:12.283186 17594 tablet_bootstrap.cc:492] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Bootstrap starting.
I20260812 06:18:12.284070 17594 tablet_bootstrap.cc:654] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:12.285079 17594 tablet_bootstrap.cc:492] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: No bootstrap required, opened a new log
I20260812 06:18:12.285187 17594 ts_tablet_manager.cc:1403] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:18:12.285562 17594 raft_consensus.cc:359] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cda2153ed93843dbacb43b5df11ad8ed" member_type: VOTER last_known_addr { host: "127.16.156.129" port: 38725 } }
I20260812 06:18:12.285670 17594 raft_consensus.cc:385] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:12.285717 17594 raft_consensus.cc:740] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: cda2153ed93843dbacb43b5df11ad8ed, State: Initialized, Role: FOLLOWER
I20260812 06:18:12.285883 17594 consensus_queue.cc:260] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed [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: "cda2153ed93843dbacb43b5df11ad8ed" member_type: VOTER last_known_addr { host: "127.16.156.129" port: 38725 } }
I20260812 06:18:12.286000 17594 raft_consensus.cc:399] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:12.286053 17594 raft_consensus.cc:493] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:12.286118 17594 raft_consensus.cc:3060] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:12.286854 17594 raft_consensus.cc:515] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cda2153ed93843dbacb43b5df11ad8ed" member_type: VOTER last_known_addr { host: "127.16.156.129" port: 38725 } }
I20260812 06:18:12.287015 17594 leader_election.cc:304] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed [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: cda2153ed93843dbacb43b5df11ad8ed; no voters: 
I20260812 06:18:12.287278 17594 leader_election.cc:290] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:12.287387 17596 raft_consensus.cc:2804] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:12.287680 17574 heartbeater.cc:499] Master 127.16.156.190:45711 was elected leader, sending a full tablet report...
I20260812 06:18:12.287611 17596 raft_consensus.cc:697] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed [term 1 LEADER]: Becoming Leader. State: Replica: cda2153ed93843dbacb43b5df11ad8ed, State: Running, Role: LEADER
I20260812 06:18:12.287868 17596 consensus_queue.cc:237] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed [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: "cda2153ed93843dbacb43b5df11ad8ed" member_type: VOTER last_known_addr { host: "127.16.156.129" port: 38725 } }
I20260812 06:18:12.287918 17594 ts_tablet_manager.cc:1434] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Time spent starting tablet: real 0.003s	user 0.001s	sys 0.002s
I20260812 06:18:12.289108 17368 catalog_manager.cc:5719] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed reported cstate change: term changed from 0 to 1, leader changed from <none> to cda2153ed93843dbacb43b5df11ad8ed (127.16.156.129). New cstate: current_term: 1 leader_uuid: "cda2153ed93843dbacb43b5df11ad8ed" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cda2153ed93843dbacb43b5df11ad8ed" member_type: VOTER last_known_addr { host: "127.16.156.129" port: 38725 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:12.349633 17010 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.018s	sys 0.004s
I20260812 06:18:12.505353 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushMRSOp(f3bc13089fa64684b2deb6640517192a): perf score=19.054940
I20260812 06:18:12.687188 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushMRSOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.182s	user 0.122s	sys 0.055s Metrics: {"bytes_written":12676711,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":182,"dirs.run_wall_time_us":789,"drs_written":1,"lbm_read_time_us":84,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44940,"lbm_writes_lt_1ms":766,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":11136,"update_count":1545}
I20260812 06:18:12.687870 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling LogGCOp(f3bc13089fa64684b2deb6640517192a): free 20743880 bytes of WAL
I20260812 06:18:12.688114 17477 log_reader.cc:385] T f3bc13089fa64684b2deb6640517192a: removed 2 log segments from log reader
I20260812 06:18:12.688210 17477 log.cc:1079] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/f3bc13089fa64684b2deb6640517192a/wal-000000001 (ops 1-6)
I20260812 06:18:12.688288 17477 log.cc:1079] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/f3bc13089fa64684b2deb6640517192a/wal-000000002 (ops 7-11)
I20260812 06:18:12.693364 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: LogGCOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:18:12.693728 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling UndoDeltaBlockGCOp(f3bc13089fa64684b2deb6640517192a): 16411396 bytes on disk
I20260812 06:18:12.694290 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: UndoDeltaBlockGCOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":110,"lbm_reads_lt_1ms":4}
I20260812 06:18:12.694748 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=2.188937
I20260812 06:18:12.715471 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.021s	user 0.014s	sys 0.000s Metrics: {"bytes_written":3733434,"delete_count":0,"lbm_write_time_us":5134,"lbm_writes_lt_1ms":94,"reinsert_count":0,"update_count":455}
I20260812 06:18:12.715972 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=2.188937
I20260812 06:18:12.733862 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.018s	user 0.008s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6925,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.734477 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling MajorDeltaCompactionOp(f3bc13089fa64684b2deb6640517192a): perf score=1.000000
I20260812 06:18:12.916538 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: MajorDeltaCompactionOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.182s	user 0.113s	sys 0.067s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774804,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":850,"lbm_read_time_us":13518,"lbm_reads_lt_1ms":569,"lbm_write_time_us":29963,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":372,"threads_started":5,"update_count":2500}
I20260812 06:18:12.917179 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=14.095187
I20260812 06:18:12.986903 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.070s	user 0.025s	sys 0.028s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24912,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:12.987466 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=2.188937
I20260812 06:18:12.999068 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4625,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.999646 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling MajorDeltaCompactionOp(f3bc13089fa64684b2deb6640517192a): perf score=1.000000
I20260812 06:18:13.189653 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: MajorDeltaCompactionOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.190s	user 0.135s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":292,"lbm_read_time_us":12356,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33125,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8704,"update_count":2500}
I20260812 06:18:13.190191 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=14.095187
I20260812 06:18:13.260682 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.070s	user 0.034s	sys 0.035s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":29255,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:13.261360 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=2.188937
I20260812 06:18:13.272714 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4564,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.273304 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling MajorDeltaCompactionOp(f3bc13089fa64684b2deb6640517192a): perf score=1.000000
I20260812 06:18:13.476851 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: MajorDeltaCompactionOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.203s	user 0.114s	sys 0.083s 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":110,"lbm_read_time_us":13842,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33883,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16896,"update_count":2500}
I20260812 06:18:13.477466 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=14.095187
I20260812 06:18:13.540325 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.062s	user 0.030s	sys 0.022s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18953,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:13.540989 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=2.188937
I20260812 06:18:13.554804 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5569,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.555521 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling MajorDeltaCompactionOp(f3bc13089fa64684b2deb6640517192a): perf score=1.000000
I20260812 06:18:13.733332 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: MajorDeltaCompactionOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.178s	user 0.082s	sys 0.088s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":678,"lbm_read_time_us":12402,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26939,"lbm_writes_lt_1ms":543,"mutex_wait_us":309,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13824,"update_count":2500}
I20260812 06:18:13.733901 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=14.095187
I20260812 06:18:13.789721 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.056s	user 0.018s	sys 0.029s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21979,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:13.790230 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=2.188937
I20260812 06:18:13.811050 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.021s	user 0.010s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4257,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.811542 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling MajorDeltaCompactionOp(f3bc13089fa64684b2deb6640517192a): perf score=1.000000
I20260812 06:18:14.002840 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: MajorDeltaCompactionOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.191s	user 0.095s	sys 0.086s 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":288,"lbm_read_time_us":13470,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28417,"lbm_writes_lt_1ms":543,"mutex_wait_us":37,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5632,"update_count":2500}
I20260812 06:18:14.003461 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=14.095187
I20260812 06:18:14.066712 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.063s	user 0.026s	sys 0.025s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24573,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:14.067271 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=2.188937
I20260812 06:18:14.079108 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.012s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4378,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.079692 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushMRSOp(f3bc13089fa64684b2deb6640517192a): perf score=1.000000
I20260812 06:18:14.121137 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushMRSOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.041s	user 0.028s	sys 0.011s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":271,"dirs.run_wall_time_us":1182,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1498,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:14.121848 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling LogGCOp(f3bc13089fa64684b2deb6640517192a): free 120553324 bytes of WAL
I20260812 06:18:14.122103 17477 log_reader.cc:385] T f3bc13089fa64684b2deb6640517192a: removed 12 log segments from log reader
I20260812 06:18:14.122164 17477 log.cc:1079] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/f3bc13089fa64684b2deb6640517192a/wal-000000003 (ops 12-16)
I20260812 06:18:14.122215 17477 log.cc:1079] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/f3bc13089fa64684b2deb6640517192a/wal-000000004 (ops 17-21)
I20260812 06:18:14.122273 17477 log.cc:1079] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/f3bc13089fa64684b2deb6640517192a/wal-000000005 (ops 22-26)
I20260812 06:18:14.122318 17477 log.cc:1079] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/f3bc13089fa64684b2deb6640517192a/wal-000000006 (ops 27-30)
I20260812 06:18:14.122359 17477 log.cc:1079] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/f3bc13089fa64684b2deb6640517192a/wal-000000007 (ops 31-35)
I20260812 06:18:14.122399 17477 log.cc:1079] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/f3bc13089fa64684b2deb6640517192a/wal-000000008 (ops 36-40)
I20260812 06:18:14.122439 17477 log.cc:1079] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/f3bc13089fa64684b2deb6640517192a/wal-000000009 (ops 41-45)
I20260812 06:18:14.122479 17477 log.cc:1079] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/f3bc13089fa64684b2deb6640517192a/wal-000000010 (ops 46-50)
I20260812 06:18:14.122522 17477 log.cc:1079] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/f3bc13089fa64684b2deb6640517192a/wal-000000011 (ops 51-55)
I20260812 06:18:14.122562 17477 log.cc:1079] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/f3bc13089fa64684b2deb6640517192a/wal-000000012 (ops 56-60)
I20260812 06:18:14.122601 17477 log.cc:1079] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/f3bc13089fa64684b2deb6640517192a/wal-000000013 (ops 61-64)
I20260812 06:18:14.122639 17477 log.cc:1079] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/f3bc13089fa64684b2deb6640517192a/wal-000000014 (ops 65-69)
I20260812 06:18:14.147389 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: LogGCOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.025s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:18:14.147765 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling UndoDeltaBlockGCOp(f3bc13089fa64684b2deb6640517192a): 472 bytes on disk
I20260812 06:18:14.148270 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: UndoDeltaBlockGCOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4}
I20260812 06:18:14.149869 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=2.188937
I20260812 06:18:14.162729 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.013s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4266759,"delete_count":0,"lbm_write_time_us":4713,"lbm_writes_lt_1ms":107,"reinsert_count":0,"update_count":520}
I20260812 06:18:14.163282 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling MajorDeltaCompactionOp(f3bc13089fa64684b2deb6640517192a): perf score=1.000000
I20260812 06:18:14.380178 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: MajorDeltaCompactionOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.217s	user 0.143s	sys 0.064s Metrics: {"cfile_cache_miss":637,"cfile_cache_miss_bytes":29041319,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":716,"lbm_read_time_us":14668,"lbm_reads_lt_1ms":669,"lbm_write_time_us":35155,"lbm_writes_lt_1ms":647,"mutex_wait_us":27,"peak_mem_usage":75706612,"reinsert_count":0,"spinlock_wait_cycles":8192,"thread_start_us":81,"threads_started":1,"update_count":3020}
I20260812 06:18:14.380801 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=18.063937
I20260812 06:18:14.452659 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.072s	user 0.035s	sys 0.035s Metrics: {"bytes_written":20348222,"delete_count":0,"lbm_write_time_us":28822,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":498,"reinsert_count":0,"update_count":2480}
I20260812 06:18:14.453231 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=2.188937
I20260812 06:18:14.465245 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.012s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4385,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.465752 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling MajorDeltaCompactionOp(f3bc13089fa64684b2deb6640517192a): perf score=1.000000
I20260812 06:18:14.657181 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: MajorDeltaCompactionOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.191s	user 0.127s	sys 0.064s Metrics: {"cfile_cache_miss":628,"cfile_cache_miss_bytes":28713009,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":860,"lbm_read_time_us":14383,"lbm_reads_lt_1ms":668,"lbm_write_time_us":32283,"lbm_writes_lt_1ms":639,"mutex_wait_us":29,"peak_mem_usage":74337948,"reinsert_count":0,"spinlock_wait_cycles":6912,"update_count":2980}
I20260812 06:18:14.657800 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=14.095187
I20260812 06:18:14.709916 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.052s	user 0.037s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22263,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:14.710522 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=2.188937
I20260812 06:18:14.737294 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.027s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5786,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.737753 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=2.188937
I20260812 06:18:14.748302 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4001,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.748769 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling MajorDeltaCompactionOp(f3bc13089fa64684b2deb6640517192a): perf score=1.000000
I20260812 06:18:14.957418 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: MajorDeltaCompactionOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.208s	user 0.133s	sys 0.075s 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":329,"lbm_read_time_us":15340,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32671,"lbm_writes_lt_1ms":643,"mutex_wait_us":51,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":29824,"update_count":3000}
I20260812 06:18:14.958334 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=14.095187
I20260812 06:18:15.009603 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.051s	user 0.038s	sys 0.004s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19422,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:15.010152 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=2.188937
I20260812 06:18:15.022107 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4739,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.023075 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling MajorDeltaCompactionOp(f3bc13089fa64684b2deb6640517192a): perf score=1.000000
I20260812 06:18:15.206110 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: MajorDeltaCompactionOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.183s	user 0.136s	sys 0.045s 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":338,"lbm_read_time_us":12403,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32753,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:18:15.206832 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=14.095187
I20260812 06:18:15.254808 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.048s	user 0.024s	sys 0.019s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":20918,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:15.255501 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=2.188937
I20260812 06:18:15.272696 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.017s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6593,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.273329 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling MajorDeltaCompactionOp(f3bc13089fa64684b2deb6640517192a): perf score=1.000000
I20260812 06:18:15.447906 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: MajorDeltaCompactionOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.174s	user 0.111s	sys 0.063s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774692,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":235,"lbm_read_time_us":13548,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28052,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9216,"update_count":2500}
I20260812 06:18:15.448606 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=14.095187
I20260812 06:18:15.508426 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.060s	user 0.031s	sys 0.022s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19211,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:15.509132 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=2.188937
I20260812 06:18:15.523571 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.014s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5874,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.524034 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushMRSOp(f3bc13089fa64684b2deb6640517192a): perf score=1.000000
I20260812 06:18:15.570061 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushMRSOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.046s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":196,"dirs.run_wall_time_us":1348,"drs_written":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1488,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:15.570747 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling LogGCOp(f3bc13089fa64684b2deb6640517192a): free 112239375 bytes of WAL
I20260812 06:18:15.570976 17477 log_reader.cc:385] T f3bc13089fa64684b2deb6640517192a: removed 11 log segments from log reader
I20260812 06:18:15.571027 17477 log.cc:1079] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/f3bc13089fa64684b2deb6640517192a/wal-000000015 (ops 70-74)
I20260812 06:18:15.571082 17477 log.cc:1079] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/f3bc13089fa64684b2deb6640517192a/wal-000000016 (ops 75-78)
I20260812 06:18:15.571128 17477 log.cc:1079] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/f3bc13089fa64684b2deb6640517192a/wal-000000017 (ops 79-83)
I20260812 06:18:15.571172 17477 log.cc:1079] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/f3bc13089fa64684b2deb6640517192a/wal-000000018 (ops 84-88)
I20260812 06:18:15.571233 17477 log.cc:1079] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/f3bc13089fa64684b2deb6640517192a/wal-000000019 (ops 89-93)
I20260812 06:18:15.571274 17477 log.cc:1079] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/f3bc13089fa64684b2deb6640517192a/wal-000000020 (ops 94-98)
I20260812 06:18:15.571316 17477 log.cc:1079] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/f3bc13089fa64684b2deb6640517192a/wal-000000021 (ops 99-103)
I20260812 06:18:15.571354 17477 log.cc:1079] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/f3bc13089fa64684b2deb6640517192a/wal-000000022 (ops 104-108)
I20260812 06:18:15.571393 17477 log.cc:1079] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/f3bc13089fa64684b2deb6640517192a/wal-000000023 (ops 109-113)
I20260812 06:18:15.571431 17477 log.cc:1079] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/f3bc13089fa64684b2deb6640517192a/wal-000000024 (ops 114-118)
I20260812 06:18:15.571470 17477 log.cc:1079] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/f3bc13089fa64684b2deb6640517192a/wal-000000025 (ops 119-123)
I20260812 06:18:15.593493 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: LogGCOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.023s	user 0.002s	sys 0.019s Metrics: {}
I20260812 06:18:15.593904 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling UndoDeltaBlockGCOp(f3bc13089fa64684b2deb6640517192a): 447 bytes on disk
I20260812 06:18:15.594333 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: UndoDeltaBlockGCOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:18:15.594890 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=2.188937
I20260812 06:18:15.617218 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.022s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6400,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.617738 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=2.188937
I20260812 06:18:15.628137 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4014,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.628842 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling MajorDeltaCompactionOp(f3bc13089fa64684b2deb6640517192a): perf score=1.000000
I20260812 06:18:15.878412 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: MajorDeltaCompactionOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.249s	user 0.163s	sys 0.076s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979749,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":673,"lbm_read_time_us":16291,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41407,"lbm_writes_lt_1ms":743,"mutex_wait_us":520,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":13568,"thread_start_us":75,"threads_started":1,"update_count":3500}
I20260812 06:18:15.880694 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=18.063937
I20260812 06:18:15.942988 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.062s	user 0.026s	sys 0.032s Metrics: {"bytes_written":20512319,"delete_count":0,"lbm_write_time_us":26700,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:15.943647 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=2.188937
I20260812 06:18:15.968104 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.024s	user 0.001s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4529,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.968694 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=2.188937
I20260812 06:18:15.978994 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.010s	user 0.007s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3838,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.979509 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling MajorDeltaCompactionOp(f3bc13089fa64684b2deb6640517192a): perf score=1.000000
I20260812 06:18:16.185506 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: MajorDeltaCompactionOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.206s	user 0.171s	sys 0.027s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979637,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":302,"lbm_read_time_us":14596,"lbm_reads_lt_1ms":773,"lbm_write_time_us":37445,"lbm_writes_lt_1ms":743,"mutex_wait_us":29,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":3500}
I20260812 06:18:16.186230 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=18.063937
I20260812 06:18:16.241526 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.055s	user 0.037s	sys 0.015s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":24327,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:16.242051 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=2.188937
I20260812 06:18:16.255484 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.013s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4989,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.256080 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling MajorDeltaCompactionOp(f3bc13089fa64684b2deb6640517192a): perf score=1.000000
I20260812 06:18:16.421157 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: MajorDeltaCompactionOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.165s	user 0.128s	sys 0.036s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":248,"lbm_read_time_us":11706,"lbm_reads_lt_1ms":664,"lbm_write_time_us":34360,"lbm_writes_lt_1ms":643,"mutex_wait_us":50,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":3000}
I20260812 06:18:16.421737 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=14.095187
I20260812 06:18:16.463295 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.041s	user 0.031s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18676,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:16.463814 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=2.188937
I20260812 06:18:16.474263 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4067,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.474709 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling MajorDeltaCompactionOp(f3bc13089fa64684b2deb6640517192a): perf score=1.000000
I20260812 06:18:16.635828 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: MajorDeltaCompactionOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.161s	user 0.103s	sys 0.056s 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":222,"lbm_read_time_us":12326,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30341,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20864,"update_count":2500}
I20260812 06:18:16.636650 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=12.110812
I20260812 06:18:16.682384 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.046s	user 0.030s	sys 0.012s Metrics: {"bytes_written":13661280,"delete_count":0,"lbm_write_time_us":19784,"lbm_writes_lt_1ms":336,"reinsert_count":0,"update_count":1665}
I20260812 06:18:16.682855 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=1.196750
I20260812 06:18:16.694132 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.011s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3159085,"delete_count":0,"lbm_write_time_us":3276,"lbm_writes_lt_1ms":80,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":385}
I20260812 06:18:16.694550 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling MajorDeltaCompactionOp(f3bc13089fa64684b2deb6640517192a): perf score=1.000000
I20260812 06:18:16.859762 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: MajorDeltaCompactionOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.165s	user 0.105s	sys 0.051s Metrics: {"cfile_cache_miss":442,"cfile_cache_miss_bytes":21082493,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2749,"lbm_read_time_us":10551,"lbm_reads_lt_1ms":474,"lbm_write_time_us":24844,"lbm_writes_lt_1ms":453,"mutex_wait_us":2062,"peak_mem_usage":51099678,"reinsert_count":0,"spinlock_wait_cycles":10240,"update_count":2050}
I20260812 06:18:16.860563 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=14.095187
I20260812 06:18:16.907763 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.047s	user 0.037s	sys 0.008s Metrics: {"bytes_written":15999662,"delete_count":0,"lbm_write_time_us":20254,"lbm_writes_lt_1ms":393,"reinsert_count":0,"update_count":1950}
I20260812 06:18:16.908308 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=2.188937
I20260812 06:18:16.931295 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.023s	user 0.007s	sys 0.016s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4319,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.931807 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushMRSOp(f3bc13089fa64684b2deb6640517192a): perf score=1.000000
I20260812 06:18:16.971958 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushMRSOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.040s	user 0.034s	sys 0.005s Metrics: {"bytes_written":1193505,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":255,"dirs.run_wall_time_us":1425,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1980,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:16.972975 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling LogGCOp(f3bc13089fa64684b2deb6640517192a): free 121006682 bytes of WAL
I20260812 06:18:16.973287 17477 log_reader.cc:385] T f3bc13089fa64684b2deb6640517192a: removed 12 log segments from log reader
I20260812 06:18:16.973392 17477 log.cc:1079] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/f3bc13089fa64684b2deb6640517192a/wal-000000026 (ops 124-128)
I20260812 06:18:16.973459 17477 log.cc:1079] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/f3bc13089fa64684b2deb6640517192a/wal-000000027 (ops 129-132)
I20260812 06:18:16.973526 17477 log.cc:1079] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/f3bc13089fa64684b2deb6640517192a/wal-000000028 (ops 133-137)
I20260812 06:18:16.973579 17477 log.cc:1079] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/f3bc13089fa64684b2deb6640517192a/wal-000000029 (ops 138-142)
I20260812 06:18:16.973623 17477 log.cc:1079] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/f3bc13089fa64684b2deb6640517192a/wal-000000030 (ops 143-147)
I20260812 06:18:16.973667 17477 log.cc:1079] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/f3bc13089fa64684b2deb6640517192a/wal-000000031 (ops 148-152)
I20260812 06:18:16.973711 17477 log.cc:1079] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/f3bc13089fa64684b2deb6640517192a/wal-000000032 (ops 153-157)
I20260812 06:18:16.973755 17477 log.cc:1079] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/f3bc13089fa64684b2deb6640517192a/wal-000000033 (ops 158-162)
I20260812 06:18:16.973799 17477 log.cc:1079] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/f3bc13089fa64684b2deb6640517192a/wal-000000034 (ops 163-167)
I20260812 06:18:16.973845 17477 log.cc:1079] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/f3bc13089fa64684b2deb6640517192a/wal-000000035 (ops 168-172)
I20260812 06:18:16.973896 17477 log.cc:1079] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/f3bc13089fa64684b2deb6640517192a/wal-000000036 (ops 173-177)
I20260812 06:18:16.973932 17477 log.cc:1079] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/f3bc13089fa64684b2deb6640517192a/wal-000000037 (ops 178-182)
I20260812 06:18:17.004500 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: LogGCOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.031s	user 0.003s	sys 0.027s Metrics: {}
I20260812 06:18:17.004988 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling UndoDeltaBlockGCOp(f3bc13089fa64684b2deb6640517192a): 463 bytes on disk
I20260812 06:18:17.005594 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: UndoDeltaBlockGCOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4}
I20260812 06:18:17.006199 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=3.181125
I20260812 06:18:17.025731 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.019s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6940,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:17.026306 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling LogGCOp(f3bc13089fa64684b2deb6640517192a): free 11564893 bytes of WAL
I20260812 06:18:17.026573 17477 log_reader.cc:385] T f3bc13089fa64684b2deb6640517192a: removed 1 log segments from log reader
I20260812 06:18:17.026635 17477 log.cc:1079] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: Deleting log segment in path: /tmp/dist-test-taskCKRnlb/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515486462175-17010-0/minicluster-data/ts-0-root/wals/f3bc13089fa64684b2deb6640517192a/wal-000000038 (ops 183-186)
I20260812 06:18:17.029495 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: LogGCOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:18:17.029861 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=2.188937
I20260812 06:18:17.045063 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.015s	user 0.005s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5463,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:17.045676 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling MajorDeltaCompactionOp(f3bc13089fa64684b2deb6640517192a): perf score=1.000000
I20260812 06:18:17.285604 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: MajorDeltaCompactionOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.240s	user 0.167s	sys 0.071s Metrics: {"cfile_cache_miss":724,"cfile_cache_miss_bytes":32569501,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1591,"lbm_read_time_us":15322,"lbm_reads_lt_1ms":764,"lbm_write_time_us":40941,"lbm_writes_lt_1ms":733,"mutex_wait_us":29,"peak_mem_usage":86518310,"reinsert_count":0,"spinlock_wait_cycles":12288,"thread_start_us":86,"threads_started":1,"update_count":3450}
I20260812 06:18:17.286402 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=18.063937
I20260812 06:18:17.361478 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.075s	user 0.046s	sys 0.020s Metrics: {"bytes_written":20512313,"delete_count":0,"lbm_write_time_us":31662,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:17.362171 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a): perf score=2.188937
I20260812 06:18:17.373497 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: FlushDeltaMemStoresOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4264,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.374092 17575 maintenance_manager.cc:419] P cda2153ed93843dbacb43b5df11ad8ed: Scheduling MajorDeltaCompactionOp(f3bc13089fa64684b2deb6640517192a): perf score=1.000000
I20260812 06:18:17.402863 17010 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.053s	user 1.815s	sys 0.237s
I20260812 06:18:17.477715 17010 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.074s	user 0.000s	sys 0.000s
I20260812 06:18:17.478282 17010 tablet_server.cc:179] TabletServer@127.16.156.129:0 shutting down...
I20260812 06:18:17.547710 17477 maintenance_manager.cc:643] P cda2153ed93843dbacb43b5df11ad8ed: MajorDeltaCompactionOp(f3bc13089fa64684b2deb6640517192a) complete. Timing: real 0.173s	user 0.112s	sys 0.060s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877100,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":756,"lbm_read_time_us":14001,"lbm_reads_lt_1ms":668,"lbm_write_time_us":29881,"lbm_writes_lt_1ms":643,"mutex_wait_us":163,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":14208,"update_count":3000}
I20260812 06:18:17.548410 17010 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:17.548640 17010 tablet_replica.cc:333] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed: stopping tablet replica
I20260812 06:18:17.548799 17010 raft_consensus.cc:2243] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:17.548991 17010 raft_consensus.cc:2272] T f3bc13089fa64684b2deb6640517192a P cda2153ed93843dbacb43b5df11ad8ed [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:17.566512 17010 tablet_server.cc:196] TabletServer@127.16.156.129:0 shutdown complete.
I20260812 06:18:17.600821 17010 master.cc:562] Master@127.16.156.190:45711 shutting down...
I20260812 06:18:17.604492 17010 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 76a6bc94b0cd4d3bba1c6365a6521845 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:17.604701 17010 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 76a6bc94b0cd4d3bba1c6365a6521845 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:17.604782 17010 tablet_replica.cc:333] T 00000000000000000000000000000000 P 76a6bc94b0cd4d3bba1c6365a6521845: stopping tablet replica
I20260812 06:18:17.617309 17010 master.cc:584] Master@127.16.156.190:45711 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5564 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11233 ms total)

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