[==========] 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:19:40.605597 13358 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.13.11.190:36317
I20260812 06:19:40.606597 13358 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:19:40.607177 13358 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:40.613483 13366 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:19:40.613518 13358 server_base.cc:1061] running on GCE node
W20260812 06:19:40.613477 13364 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:19:40.613742 13363 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:19:40.614310 13358 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:40.614413 13358 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:19:40.614445 13358 hybrid_clock.cc:648] HybridClock initialized: now 1786515580614443 us; error 0 us; skew 500 ppm
I20260812 06:19:40.616201 13358 webserver.cc:533] Webserver started at http://127.13.11.190:42811/ using document root <none> and password file <none>
I20260812 06:19:40.616688 13358 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:40.616757 13358 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:40.616948 13358 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:40.618517 13358 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/master-0-root/instance:
uuid: "dc93433bb6a9464893502bd8e9b38ff2"
format_stamp: "Formatted at 2026-08-12 06:19:40 on dist-test-slave-bxbt"
I20260812 06:19:40.622223 13358 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:19:40.624603 13371 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:19:40.625612 13358 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:40.625730 13358 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/master-0-root
uuid: "dc93433bb6a9464893502bd8e9b38ff2"
format_stamp: "Formatted at 2026-08-12 06:19:40 on dist-test-slave-bxbt"
I20260812 06:19:40.625854 13358 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-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:19:40.644991 13358 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:40.645619 13358 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:19:40.645802 13358 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:40.653439 13358 rpc_server.cc:307] RPC server started. Bound to: 127.13.11.190:36317
I20260812 06:19:40.653448 13423 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.11.190:36317 every 8 connection(s)
I20260812 06:19:40.655617 13424 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:19:40.660966 13424 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P dc93433bb6a9464893502bd8e9b38ff2: Bootstrap starting.
I20260812 06:19:40.663213 13424 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P dc93433bb6a9464893502bd8e9b38ff2: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:40.664170 13424 log.cc:826] T 00000000000000000000000000000000 P dc93433bb6a9464893502bd8e9b38ff2: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:40.665803 13424 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P dc93433bb6a9464893502bd8e9b38ff2: No bootstrap required, opened a new log
I20260812 06:19:40.668630 13424 raft_consensus.cc:359] T 00000000000000000000000000000000 P dc93433bb6a9464893502bd8e9b38ff2 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dc93433bb6a9464893502bd8e9b38ff2" member_type: VOTER }
I20260812 06:19:40.668789 13424 raft_consensus.cc:385] T 00000000000000000000000000000000 P dc93433bb6a9464893502bd8e9b38ff2 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:40.668891 13424 raft_consensus.cc:740] T 00000000000000000000000000000000 P dc93433bb6a9464893502bd8e9b38ff2 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: dc93433bb6a9464893502bd8e9b38ff2, State: Initialized, Role: FOLLOWER
I20260812 06:19:40.669498 13424 consensus_queue.cc:260] T 00000000000000000000000000000000 P dc93433bb6a9464893502bd8e9b38ff2 [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: "dc93433bb6a9464893502bd8e9b38ff2" member_type: VOTER }
I20260812 06:19:40.669661 13424 raft_consensus.cc:399] T 00000000000000000000000000000000 P dc93433bb6a9464893502bd8e9b38ff2 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:40.669751 13424 raft_consensus.cc:493] T 00000000000000000000000000000000 P dc93433bb6a9464893502bd8e9b38ff2 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:40.669901 13424 raft_consensus.cc:3060] T 00000000000000000000000000000000 P dc93433bb6a9464893502bd8e9b38ff2 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:40.670694 13424 raft_consensus.cc:515] T 00000000000000000000000000000000 P dc93433bb6a9464893502bd8e9b38ff2 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dc93433bb6a9464893502bd8e9b38ff2" member_type: VOTER }
I20260812 06:19:40.671159 13424 leader_election.cc:304] T 00000000000000000000000000000000 P dc93433bb6a9464893502bd8e9b38ff2 [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: dc93433bb6a9464893502bd8e9b38ff2; no voters: 
I20260812 06:19:40.671653 13424 leader_election.cc:290] T 00000000000000000000000000000000 P dc93433bb6a9464893502bd8e9b38ff2 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:40.671837 13427 raft_consensus.cc:2804] T 00000000000000000000000000000000 P dc93433bb6a9464893502bd8e9b38ff2 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:40.672120 13427 raft_consensus.cc:697] T 00000000000000000000000000000000 P dc93433bb6a9464893502bd8e9b38ff2 [term 1 LEADER]: Becoming Leader. State: Replica: dc93433bb6a9464893502bd8e9b38ff2, State: Running, Role: LEADER
I20260812 06:19:40.672539 13427 consensus_queue.cc:237] T 00000000000000000000000000000000 P dc93433bb6a9464893502bd8e9b38ff2 [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: "dc93433bb6a9464893502bd8e9b38ff2" member_type: VOTER }
I20260812 06:19:40.672711 13424 sys_catalog.cc:565] T 00000000000000000000000000000000 P dc93433bb6a9464893502bd8e9b38ff2 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:40.674398 13429 sys_catalog.cc:455] T 00000000000000000000000000000000 P dc93433bb6a9464893502bd8e9b38ff2 [sys.catalog]: SysCatalogTable state changed. Reason: New leader dc93433bb6a9464893502bd8e9b38ff2. Latest consensus state: current_term: 1 leader_uuid: "dc93433bb6a9464893502bd8e9b38ff2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dc93433bb6a9464893502bd8e9b38ff2" member_type: VOTER } }
I20260812 06:19:40.674435 13428 sys_catalog.cc:455] T 00000000000000000000000000000000 P dc93433bb6a9464893502bd8e9b38ff2 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "dc93433bb6a9464893502bd8e9b38ff2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dc93433bb6a9464893502bd8e9b38ff2" member_type: VOTER } }
I20260812 06:19:40.674522 13428 sys_catalog.cc:458] T 00000000000000000000000000000000 P dc93433bb6a9464893502bd8e9b38ff2 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:40.674521 13429 sys_catalog.cc:458] T 00000000000000000000000000000000 P dc93433bb6a9464893502bd8e9b38ff2 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:40.674898 13438 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:40.675112 13358 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:40.677130 13438 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:40.681661 13438 catalog_manager.cc:1383] Generated new cluster ID: 864db4257a034718812b5a093064a001
I20260812 06:19:40.681726 13438 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:40.693042 13438 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:40.694132 13438 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:40.711256 13438 catalog_manager.cc:6092] T 00000000000000000000000000000000 P dc93433bb6a9464893502bd8e9b38ff2: Generated new TSK 0
I20260812 06:19:40.712057 13438 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:40.740152 13358 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:40.743094 13447 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:19:40.743078 13446 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:19:40.743078 13449 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:19:40.743631 13358 server_base.cc:1061] running on GCE node
I20260812 06:19:40.743846 13358 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:40.743911 13358 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:19:40.743954 13358 hybrid_clock.cc:648] HybridClock initialized: now 1786515580743953 us; error 0 us; skew 500 ppm
I20260812 06:19:40.744966 13358 webserver.cc:533] Webserver started at http://127.13.11.129:46333/ using document root <none> and password file <none>
I20260812 06:19:40.745162 13358 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:40.745241 13358 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:40.745328 13358 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:40.745784 13358 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root/instance:
uuid: "1980db0089b74cbd9cbaa950d56f4d20"
format_stamp: "Formatted at 2026-08-12 06:19:40 on dist-test-slave-bxbt"
I20260812 06:19:40.747411 13358 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:40.748529 13454 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:19:40.748836 13358 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:40.748903 13358 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root
uuid: "1980db0089b74cbd9cbaa950d56f4d20"
format_stamp: "Formatted at 2026-08-12 06:19:40 on dist-test-slave-bxbt"
I20260812 06:19:40.748994 13358 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-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:19:40.758355 13358 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:40.758819 13358 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:40.759322 13358 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:40.760205 13358 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:40.760254 13358 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:40.760329 13358 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:40.760370 13358 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:40.767215 13358 rpc_server.cc:307] RPC server started. Bound to: 127.13.11.129:44683
I20260812 06:19:40.767249 13517 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.11.129:44683 every 8 connection(s)
I20260812 06:19:40.782039 13518 heartbeater.cc:344] Connected to a master server at 127.13.11.190:36317
I20260812 06:19:40.782285 13518 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:40.782755 13518 heartbeater.cc:507] Master 127.13.11.190:36317 requested a full tablet report, sending...
I20260812 06:19:40.784251 13388 ts_manager.cc:194] Registered new tserver with Master: 1980db0089b74cbd9cbaa950d56f4d20 (127.13.11.129:44683)
I20260812 06:19:40.784703 13358 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.016867753s
I20260812 06:19:40.785763 13388 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:38292
I20260812 06:19:40.794734 13388 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:38308:
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:19:40.814019 13482 tablet_service.cc:1511] Processing CreateTablet for tablet 8e4266eeab8447dea4516903891e2542 (DEFAULT_TABLE table=heavy-update-compaction-test [id=cb0be332b28941d19c5eb8bd0785ebc9]), partition=
I20260812 06:19:40.814530 13482 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 8e4266eeab8447dea4516903891e2542. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:40.817281 13530 tablet_bootstrap.cc:492] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Bootstrap starting.
I20260812 06:19:40.818233 13530 tablet_bootstrap.cc:654] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:40.819628 13530 tablet_bootstrap.cc:492] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: No bootstrap required, opened a new log
I20260812 06:19:40.819793 13530 ts_tablet_manager.cc:1403] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:40.820465 13530 raft_consensus.cc:359] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1980db0089b74cbd9cbaa950d56f4d20" member_type: VOTER last_known_addr { host: "127.13.11.129" port: 44683 } }
I20260812 06:19:40.820590 13530 raft_consensus.cc:385] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:40.820639 13530 raft_consensus.cc:740] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1980db0089b74cbd9cbaa950d56f4d20, State: Initialized, Role: FOLLOWER
I20260812 06:19:40.820776 13530 consensus_queue.cc:260] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20 [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: "1980db0089b74cbd9cbaa950d56f4d20" member_type: VOTER last_known_addr { host: "127.13.11.129" port: 44683 } }
I20260812 06:19:40.820888 13530 raft_consensus.cc:399] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:40.820937 13530 raft_consensus.cc:493] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:40.820993 13530 raft_consensus.cc:3060] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:40.821722 13530 raft_consensus.cc:515] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1980db0089b74cbd9cbaa950d56f4d20" member_type: VOTER last_known_addr { host: "127.13.11.129" port: 44683 } }
I20260812 06:19:40.821878 13530 leader_election.cc:304] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20 [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: 1980db0089b74cbd9cbaa950d56f4d20; no voters: 
I20260812 06:19:40.822115 13530 leader_election.cc:290] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:40.822216 13532 raft_consensus.cc:2804] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:40.822432 13532 raft_consensus.cc:697] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20 [term 1 LEADER]: Becoming Leader. State: Replica: 1980db0089b74cbd9cbaa950d56f4d20, State: Running, Role: LEADER
I20260812 06:19:40.822496 13530 ts_tablet_manager.cc:1434] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:19:40.822628 13532 consensus_queue.cc:237] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20 [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: "1980db0089b74cbd9cbaa950d56f4d20" member_type: VOTER last_known_addr { host: "127.13.11.129" port: 44683 } }
I20260812 06:19:40.822790 13518 heartbeater.cc:499] Master 127.13.11.190:36317 was elected leader, sending a full tablet report...
I20260812 06:19:40.825387 13388 catalog_manager.cc:5719] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20 reported cstate change: term changed from 0 to 1, leader changed from <none> to 1980db0089b74cbd9cbaa950d56f4d20 (127.13.11.129). New cstate: current_term: 1 leader_uuid: "1980db0089b74cbd9cbaa950d56f4d20" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1980db0089b74cbd9cbaa950d56f4d20" member_type: VOTER last_known_addr { host: "127.13.11.129" port: 44683 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:40.892851 13358 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.061s	user 0.023s	sys 0.008s
I20260812 06:19:41.018307 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushMRSOp(8e4266eeab8447dea4516903891e2542): perf score=18.062753
I20260812 06:19:41.189497 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushMRSOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.171s	user 0.124s	sys 0.045s Metrics: {"bytes_written":12635684,"cfile_init":1,"compiler_manager_pool.queue_time_us":243,"delete_count":0,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":218,"dirs.run_wall_time_us":842,"drs_written":1,"lbm_read_time_us":102,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40759,"lbm_writes_lt_1ms":765,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":171776,"thread_start_us":171,"threads_started":1,"update_count":1540}
I20260812 06:19:41.190498 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling LogGCOp(8e4266eeab8447dea4516903891e2542): free 20743880 bytes of WAL
I20260812 06:19:41.190807 13459 log_reader.cc:385] T 8e4266eeab8447dea4516903891e2542: removed 2 log segments from log reader
I20260812 06:19:41.190898 13459 log.cc:1079] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/8e4266eeab8447dea4516903891e2542/wal-000000001 (ops 1-6)
I20260812 06:19:41.190976 13459 log.cc:1079] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/8e4266eeab8447dea4516903891e2542/wal-000000002 (ops 7-11)
I20260812 06:19:41.194790 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: LogGCOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.004s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:41.195112 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling UndoDeltaBlockGCOp(8e4266eeab8447dea4516903891e2542): 16411405 bytes on disk
I20260812 06:19:41.195655 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: UndoDeltaBlockGCOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:19:41.196085 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=2.188937
I20260812 06:19:41.215528 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.019s	user 0.003s	sys 0.011s Metrics: {"bytes_written":3774459,"delete_count":0,"lbm_write_time_us":5919,"lbm_writes_lt_1ms":95,"reinsert_count":0,"update_count":460}
I20260812 06:19:41.216013 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542): perf score=1.000000
I20260812 06:19:41.363442 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.147s	user 0.126s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672271,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":770,"lbm_read_time_us":7291,"lbm_reads_lt_1ms":460,"lbm_write_time_us":26870,"lbm_writes_lt_1ms":443,"mutex_wait_us":25,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":322,"threads_started":5,"update_count":2000}
I20260812 06:19:41.364054 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=10.126437
I20260812 06:19:41.399791 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.036s	user 0.019s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15205,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:41.400216 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=2.188937
I20260812 06:19:41.410648 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4031,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.411080 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542): perf score=1.000000
I20260812 06:19:41.528903 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.118s	user 0.094s	sys 0.024s 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":219,"lbm_read_time_us":8700,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21957,"lbm_writes_lt_1ms":443,"mutex_wait_us":25,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":48384,"update_count":2000}
I20260812 06:19:41.529472 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=10.126437
I20260812 06:19:41.568372 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.039s	user 0.030s	sys 0.003s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14595,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:41.568806 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=2.188937
I20260812 06:19:41.579358 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) 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:19:41.580057 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542): perf score=1.000000
I20260812 06:19:41.702128 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.122s	user 0.100s	sys 0.021s 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":353,"lbm_read_time_us":8270,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23705,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:41.702847 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=10.126437
I20260812 06:19:41.747299 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.044s	user 0.033s	sys 0.007s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16369,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:19:41.747931 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=2.188937
I20260812 06:19:41.758569 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4115,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.759044 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542): perf score=1.000000
I20260812 06:19:41.901908 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.143s	user 0.088s	sys 0.054s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":898,"lbm_read_time_us":9680,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24650,"lbm_writes_lt_1ms":443,"mutex_wait_us":266,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9856,"update_count":2000}
I20260812 06:19:41.902559 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=10.126437
I20260812 06:19:41.945971 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.043s	user 0.011s	sys 0.025s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17920,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:41.946478 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=2.188937
I20260812 06:19:41.957036 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3989,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:41.957623 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542): perf score=1.000000
I20260812 06:19:42.073195 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.115s	user 0.095s	sys 0.020s 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":734,"lbm_read_time_us":8036,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21952,"lbm_writes_lt_1ms":443,"mutex_wait_us":260,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:42.075843 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=10.126437
I20260812 06:19:42.110848 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.035s	user 0.019s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15109,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:42.111375 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=2.188937
I20260812 06:19:42.127525 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5971,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.128062 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542): perf score=1.000000
I20260812 06:19:42.262086 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.134s	user 0.090s	sys 0.042s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1193,"lbm_read_time_us":9621,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24675,"lbm_writes_lt_1ms":443,"mutex_wait_us":255,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2000}
I20260812 06:19:42.262842 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=10.126437
I20260812 06:19:42.307543 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.044s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16435,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:42.308105 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=2.188937
I20260812 06:19:42.318552 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4098,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.319216 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushMRSOp(8e4266eeab8447dea4516903891e2542): perf score=1.000000
I20260812 06:19:42.353293 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushMRSOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.034s	user 0.028s	sys 0.004s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":42,"dirs.run_cpu_time_us":237,"dirs.run_wall_time_us":998,"drs_written":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2057,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:42.354084 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling LogGCOp(8e4266eeab8447dea4516903891e2542): free 115943182 bytes of WAL
I20260812 06:19:42.354336 13459 log_reader.cc:385] T 8e4266eeab8447dea4516903891e2542: removed 11 log segments from log reader
I20260812 06:19:42.354400 13459 log.cc:1079] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/8e4266eeab8447dea4516903891e2542/wal-000000003 (ops 12-16)
I20260812 06:19:42.354449 13459 log.cc:1079] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/8e4266eeab8447dea4516903891e2542/wal-000000004 (ops 17-21)
I20260812 06:19:42.354486 13459 log.cc:1079] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/8e4266eeab8447dea4516903891e2542/wal-000000005 (ops 22-26)
I20260812 06:19:42.354526 13459 log.cc:1079] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/8e4266eeab8447dea4516903891e2542/wal-000000006 (ops 27-31)
I20260812 06:19:42.354565 13459 log.cc:1079] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/8e4266eeab8447dea4516903891e2542/wal-000000007 (ops 32-36)
I20260812 06:19:42.354604 13459 log.cc:1079] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/8e4266eeab8447dea4516903891e2542/wal-000000008 (ops 37-41)
I20260812 06:19:42.354642 13459 log.cc:1079] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/8e4266eeab8447dea4516903891e2542/wal-000000009 (ops 42-46)
I20260812 06:19:42.354682 13459 log.cc:1079] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/8e4266eeab8447dea4516903891e2542/wal-000000010 (ops 47-51)
I20260812 06:19:42.354722 13459 log.cc:1079] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/8e4266eeab8447dea4516903891e2542/wal-000000011 (ops 52-56)
I20260812 06:19:42.354759 13459 log.cc:1079] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/8e4266eeab8447dea4516903891e2542/wal-000000012 (ops 57-61)
I20260812 06:19:42.354799 13459 log.cc:1079] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/8e4266eeab8447dea4516903891e2542/wal-000000013 (ops 62-66)
I20260812 06:19:42.378791 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: LogGCOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.024s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:19:42.379248 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling UndoDeltaBlockGCOp(8e4266eeab8447dea4516903891e2542): 447 bytes on disk
I20260812 06:19:42.379724 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: UndoDeltaBlockGCOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4}
I20260812 06:19:42.380225 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=2.188937
I20260812 06:19:42.394351 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.014s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4225731,"delete_count":0,"lbm_write_time_us":4392,"lbm_writes_lt_1ms":106,"reinsert_count":0,"update_count":515}
I20260812 06:19:42.394798 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=2.188937
I20260812 06:19:42.408744 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3979584,"delete_count":0,"lbm_write_time_us":5469,"lbm_writes_lt_1ms":100,"reinsert_count":0,"update_count":485}
I20260812 06:19:42.409193 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542): perf score=1.000000
I20260812 06:19:42.590930 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.181s	user 0.121s	sys 0.060s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877334,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":995,"lbm_read_time_us":13975,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31791,"lbm_writes_lt_1ms":643,"mutex_wait_us":71,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9984,"thread_start_us":75,"threads_started":1,"update_count":3000}
I20260812 06:19:42.591626 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=14.095187
I20260812 06:19:42.641191 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.049s	user 0.019s	sys 0.028s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":21381,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:42.641690 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=2.188937
I20260812 06:19:42.653997 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.012s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4210,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:42.654563 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542): perf score=1.000000
I20260812 06:19:42.838927 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.184s	user 0.143s	sys 0.033s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":797,"lbm_read_time_us":9723,"lbm_reads_lt_1ms":572,"lbm_write_time_us":36027,"lbm_writes_lt_1ms":543,"mutex_wait_us":53,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9088,"update_count":2500}
I20260812 06:19:42.839478 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=14.095187
I20260812 06:19:42.889133 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.049s	user 0.027s	sys 0.015s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19865,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:42.889595 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542): perf score=1.000000
I20260812 06:19:43.026393 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.137s	user 0.079s	sys 0.054s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672159,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":479,"lbm_read_time_us":10646,"lbm_reads_lt_1ms":463,"lbm_write_time_us":22329,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2000}
I20260812 06:19:43.026984 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=11.118625
I20260812 06:19:43.073360 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.046s	user 0.023s	sys 0.017s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":18162,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:19:43.073963 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=2.188937
I20260812 06:19:43.085587 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3972,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.086149 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=2.188937
I20260812 06:19:43.095943 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3530,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:43.096407 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542): perf score=1.000000
I20260812 06:19:43.263417 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.167s	user 0.111s	sys 0.055s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774801,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":274,"lbm_read_time_us":12302,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27940,"lbm_writes_lt_1ms":543,"mutex_wait_us":59,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9856,"update_count":2500}
I20260812 06:19:43.264219 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=11.118625
I20260812 06:19:43.310146 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.046s	user 0.020s	sys 0.023s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":21831,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":310,"reinsert_count":0,"update_count":1550}
I20260812 06:19:43.310676 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=2.188937
I20260812 06:19:43.331421 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.021s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4774,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:43.331913 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=2.188937
I20260812 06:19:43.342095 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3782,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.342592 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542): perf score=1.000000
I20260812 06:19:43.488708 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.146s	user 0.115s	sys 0.030s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774800,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":707,"lbm_read_time_us":11985,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28178,"lbm_writes_lt_1ms":543,"mutex_wait_us":293,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1152,"update_count":2500}
I20260812 06:19:43.491878 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=10.126437
I20260812 06:19:43.526057 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.034s	user 0.026s	sys 0.006s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14476,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:43.526633 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=2.188937
I20260812 06:19:43.541851 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5611,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.542532 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542): perf score=1.000000
I20260812 06:19:43.669159 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.126s	user 0.084s	sys 0.042s 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":734,"lbm_read_time_us":8015,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24989,"lbm_writes_lt_1ms":443,"mutex_wait_us":41,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2000}
I20260812 06:19:43.669884 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=10.126437
I20260812 06:19:43.716809 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.047s	user 0.016s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14720,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:43.717432 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=2.188937
I20260812 06:19:43.729671 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.012s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4294,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:43.730427 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushMRSOp(8e4266eeab8447dea4516903891e2542): perf score=1.000000
I20260812 06:19:43.765142 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushMRSOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.035s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":224,"dirs.run_wall_time_us":1350,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1668,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:43.765941 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling LogGCOp(8e4266eeab8447dea4516903891e2542): free 116396472 bytes of WAL
I20260812 06:19:43.766175 13459 log_reader.cc:385] T 8e4266eeab8447dea4516903891e2542: removed 12 log segments from log reader
I20260812 06:19:43.766222 13459 log.cc:1079] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/8e4266eeab8447dea4516903891e2542/wal-000000014 (ops 67-71)
I20260812 06:19:43.766249 13459 log.cc:1079] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/8e4266eeab8447dea4516903891e2542/wal-000000015 (ops 72-76)
I20260812 06:19:43.766323 13459 log.cc:1079] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/8e4266eeab8447dea4516903891e2542/wal-000000016 (ops 77-80)
I20260812 06:19:43.766355 13459 log.cc:1079] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/8e4266eeab8447dea4516903891e2542/wal-000000017 (ops 81-85)
I20260812 06:19:43.766397 13459 log.cc:1079] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/8e4266eeab8447dea4516903891e2542/wal-000000018 (ops 86-90)
I20260812 06:19:43.766455 13459 log.cc:1079] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/8e4266eeab8447dea4516903891e2542/wal-000000019 (ops 91-94)
I20260812 06:19:43.766499 13459 log.cc:1079] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/8e4266eeab8447dea4516903891e2542/wal-000000020 (ops 95-99)
I20260812 06:19:43.766541 13459 log.cc:1079] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/8e4266eeab8447dea4516903891e2542/wal-000000021 (ops 100-104)
I20260812 06:19:43.766582 13459 log.cc:1079] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/8e4266eeab8447dea4516903891e2542/wal-000000022 (ops 105-108)
I20260812 06:19:43.766621 13459 log.cc:1079] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/8e4266eeab8447dea4516903891e2542/wal-000000023 (ops 109-113)
I20260812 06:19:43.766660 13459 log.cc:1079] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/8e4266eeab8447dea4516903891e2542/wal-000000024 (ops 114-118)
I20260812 06:19:43.766700 13459 log.cc:1079] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/8e4266eeab8447dea4516903891e2542/wal-000000025 (ops 119-122)
I20260812 06:19:43.792387 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: LogGCOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.026s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:43.792822 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=3.181125
I20260812 06:19:43.813141 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.020s	user 0.015s	sys 0.002s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7154,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:43.813601 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=2.188937
I20260812 06:19:43.823465 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3714,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:43.823918 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling UndoDeltaBlockGCOp(8e4266eeab8447dea4516903891e2542): 463 bytes on disk
I20260812 06:19:43.824347 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: UndoDeltaBlockGCOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:19:43.824831 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542): perf score=1.000000
I20260812 06:19:44.001453 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.176s	user 0.134s	sys 0.041s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":222,"lbm_read_time_us":12252,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34077,"lbm_writes_lt_1ms":643,"mutex_wait_us":27,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":14848,"thread_start_us":95,"threads_started":1,"update_count":3000}
I20260812 06:19:44.007160 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=14.095187
I20260812 06:19:44.055550 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.048s	user 0.035s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20520,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:44.056136 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=2.188937
I20260812 06:19:44.067191 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4032,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.067926 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542): perf score=1.000000
I20260812 06:19:44.223332 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.155s	user 0.107s	sys 0.037s 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":993,"lbm_read_time_us":9907,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28477,"lbm_writes_lt_1ms":543,"mutex_wait_us":441,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":2500}
I20260812 06:19:44.224121 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=14.095187
I20260812 06:19:44.275111 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.051s	user 0.022s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21528,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:44.275727 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542): perf score=1.000000
I20260812 06:19:44.438190 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.162s	user 0.125s	sys 0.027s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":226,"lbm_read_time_us":10284,"lbm_reads_lt_1ms":463,"lbm_write_time_us":25782,"lbm_writes_lt_1ms":443,"mutex_wait_us":50,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8192,"update_count":2000}
I20260812 06:19:44.438783 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=14.095187
I20260812 06:19:44.487915 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.049s	user 0.022s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18665,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:44.488423 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=2.188937
I20260812 06:19:44.501761 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4986,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.502303 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542): perf score=1.000000
I20260812 06:19:44.692938 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.190s	user 0.120s	sys 0.065s 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":248,"lbm_read_time_us":11003,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33620,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:44.693547 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=14.095187
I20260812 06:19:44.738519 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.045s	user 0.019s	sys 0.022s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18828,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2000}
I20260812 06:19:44.739092 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=2.188937
I20260812 06:19:44.753003 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.014s	user 0.000s	sys 0.012s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5708,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.753582 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542): perf score=1.000000
I20260812 06:19:44.917744 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.164s	user 0.128s	sys 0.034s 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":416,"lbm_read_time_us":11219,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31929,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":25344,"update_count":2500}
I20260812 06:19:44.918613 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=10.126437
I20260812 06:19:44.959487 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.041s	user 0.015s	sys 0.021s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16645,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:44.960096 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=2.188937
I20260812 06:19:44.981505 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.021s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6528,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:44.981949 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542): perf score=1.000000
I20260812 06:19:45.095117 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.113s	user 0.072s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":840,"lbm_read_time_us":7223,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22564,"lbm_writes_lt_1ms":443,"mutex_wait_us":510,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":2000}
I20260812 06:19:45.095896 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=10.126437
I20260812 06:19:45.136512 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.040s	user 0.020s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16248,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:45.137080 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=2.188937
I20260812 06:19:45.152642 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5773,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:45.153199 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushMRSOp(8e4266eeab8447dea4516903891e2542): perf score=1.000000
I20260812 06:19:45.183146 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushMRSOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.030s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1193505,"cfile_init":1,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":194,"dirs.run_wall_time_us":1213,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1438,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:45.183894 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling LogGCOp(8e4266eeab8447dea4516903891e2542): free 121006665 bytes of WAL
I20260812 06:19:45.184113 13459 log_reader.cc:385] T 8e4266eeab8447dea4516903891e2542: removed 12 log segments from log reader
I20260812 06:19:45.184156 13459 log.cc:1079] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/8e4266eeab8447dea4516903891e2542/wal-000000026 (ops 123-127)
I20260812 06:19:45.184185 13459 log.cc:1079] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/8e4266eeab8447dea4516903891e2542/wal-000000027 (ops 128-132)
I20260812 06:19:45.184249 13459 log.cc:1079] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/8e4266eeab8447dea4516903891e2542/wal-000000028 (ops 133-137)
I20260812 06:19:45.184281 13459 log.cc:1079] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/8e4266eeab8447dea4516903891e2542/wal-000000029 (ops 138-142)
I20260812 06:19:45.184320 13459 log.cc:1079] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/8e4266eeab8447dea4516903891e2542/wal-000000030 (ops 143-147)
I20260812 06:19:45.184386 13459 log.cc:1079] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/8e4266eeab8447dea4516903891e2542/wal-000000031 (ops 148-152)
I20260812 06:19:45.184425 13459 log.cc:1079] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/8e4266eeab8447dea4516903891e2542/wal-000000032 (ops 153-157)
I20260812 06:19:45.184463 13459 log.cc:1079] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/8e4266eeab8447dea4516903891e2542/wal-000000033 (ops 158-162)
I20260812 06:19:45.184502 13459 log.cc:1079] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/8e4266eeab8447dea4516903891e2542/wal-000000034 (ops 163-166)
I20260812 06:19:45.184542 13459 log.cc:1079] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/8e4266eeab8447dea4516903891e2542/wal-000000035 (ops 167-171)
I20260812 06:19:45.184580 13459 log.cc:1079] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/8e4266eeab8447dea4516903891e2542/wal-000000036 (ops 172-176)
I20260812 06:19:45.184621 13459 log.cc:1079] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/8e4266eeab8447dea4516903891e2542/wal-000000037 (ops 177-181)
I20260812 06:19:45.209412 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: LogGCOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.025s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:19:45.209961 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling UndoDeltaBlockGCOp(8e4266eeab8447dea4516903891e2542): 462 bytes on disk
I20260812 06:19:45.210517 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: UndoDeltaBlockGCOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:19:45.211113 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=2.188937
I20260812 06:19:45.225728 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.014s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4263,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:45.226168 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=2.188937
I20260812 06:19:45.240432 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102663,"delete_count":0,"lbm_write_time_us":5682,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:45.240895 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542): perf score=1.000000
I20260812 06:19:45.421702 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.181s	user 0.129s	sys 0.046s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877343,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":383,"lbm_read_time_us":11667,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36976,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":45952,"thread_start_us":75,"threads_started":1,"update_count":3000}
I20260812 06:19:45.422322 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=14.095187
I20260812 06:19:45.476413 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.054s	user 0.036s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":26434,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:45.476924 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=2.188937
I20260812 06:19:45.489341 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4513,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:45.489935 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542): perf score=1.000000
I20260812 06:19:45.600996 13358 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.708s	user 1.845s	sys 0.083s
I20260812 06:19:45.632032 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.142s	user 0.107s	sys 0.035s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"lbm_read_time_us":9114,"lbm_reads_lt_1ms":568,"lbm_write_time_us":30520,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2500}
I20260812 06:19:45.632706 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542): perf score=10.126437
I20260812 06:19:45.657821 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: FlushDeltaMemStoresOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.025s	user 0.012s	sys 0.012s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":11843,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:45.658331 13519 maintenance_manager.cc:419] P 1980db0089b74cbd9cbaa950d56f4d20: Scheduling MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542): perf score=1.000000
I20260812 06:19:45.683940 13358 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.082s	user 0.005s	sys 0.000s
I20260812 06:19:45.684773 13358 tablet_server.cc:179] TabletServer@127.13.11.129:0 shutting down...
I20260812 06:19:45.767357 13459 maintenance_manager.cc:643] P 1980db0089b74cbd9cbaa950d56f4d20: MajorDeltaCompactionOp(8e4266eeab8447dea4516903891e2542) complete. Timing: real 0.109s	user 0.076s	sys 0.032s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569749,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":361,"lbm_read_time_us":8173,"lbm_reads_lt_1ms":367,"lbm_write_time_us":20982,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":342,"mutex_wait_us":23,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":17920,"update_count":1500}
I20260812 06:19:45.768139 13358 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:45.768595 13358 tablet_replica.cc:333] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20: stopping tablet replica
I20260812 06:19:45.768898 13358 raft_consensus.cc:2243] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:45.769164 13358 raft_consensus.cc:2272] T 8e4266eeab8447dea4516903891e2542 P 1980db0089b74cbd9cbaa950d56f4d20 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:45.774601 13358 tablet_server.cc:196] TabletServer@127.13.11.129:0 shutdown complete.
I20260812 06:19:45.800028 13358 master.cc:562] Master@127.13.11.190:36317 shutting down...
I20260812 06:19:45.803771 13358 raft_consensus.cc:2243] T 00000000000000000000000000000000 P dc93433bb6a9464893502bd8e9b38ff2 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:45.803941 13358 raft_consensus.cc:2272] T 00000000000000000000000000000000 P dc93433bb6a9464893502bd8e9b38ff2 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:45.803996 13358 tablet_replica.cc:333] T 00000000000000000000000000000000 P dc93433bb6a9464893502bd8e9b38ff2: stopping tablet replica
I20260812 06:19:45.816426 13358 master.cc:584] Master@127.13.11.190:36317 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5297 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:45.903105 13358 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.13.11.190:45815
I20260812 06:19:45.903455 13358 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:45.905491 13549 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:19:45.905633 13550 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:19:45.905673 13358 server_base.cc:1061] running on GCE node
W20260812 06:19:45.905757 13552 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:19:45.906059 13358 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:45.906116 13358 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:19:45.906132 13358 hybrid_clock.cc:648] HybridClock initialized: now 1786515585906132 us; error 0 us; skew 500 ppm
I20260812 06:19:45.907017 13358 webserver.cc:533] Webserver started at http://127.13.11.190:44253/ using document root <none> and password file <none>
I20260812 06:19:45.907150 13358 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:45.907191 13358 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:45.907241 13358 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:45.907631 13358 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/master-0-root/instance:
uuid: "406ab3bbe6cd45d5aa86c9884e49ab6e"
format_stamp: "Formatted at 2026-08-12 06:19:45 on dist-test-slave-bxbt"
I20260812 06:19:45.909204 13358 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:45.910131 13557 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:19:45.910388 13358 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:45.910454 13358 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/master-0-root
uuid: "406ab3bbe6cd45d5aa86c9884e49ab6e"
format_stamp: "Formatted at 2026-08-12 06:19:45 on dist-test-slave-bxbt"
I20260812 06:19:45.910513 13358 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-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:19:45.950284 13358 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:45.950668 13358 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:45.955086 13358 rpc_server.cc:307] RPC server started. Bound to: 127.13.11.190:45815
I20260812 06:19:45.957216 13609 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.11.190:45815 every 8 connection(s)
I20260812 06:19:45.962703 13610 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:19:45.969538 13610 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 406ab3bbe6cd45d5aa86c9884e49ab6e: Bootstrap starting.
I20260812 06:19:45.970412 13610 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 406ab3bbe6cd45d5aa86c9884e49ab6e: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:45.971510 13610 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 406ab3bbe6cd45d5aa86c9884e49ab6e: No bootstrap required, opened a new log
I20260812 06:19:45.972044 13610 raft_consensus.cc:359] T 00000000000000000000000000000000 P 406ab3bbe6cd45d5aa86c9884e49ab6e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "406ab3bbe6cd45d5aa86c9884e49ab6e" member_type: VOTER }
I20260812 06:19:45.972137 13610 raft_consensus.cc:385] T 00000000000000000000000000000000 P 406ab3bbe6cd45d5aa86c9884e49ab6e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:45.972162 13610 raft_consensus.cc:740] T 00000000000000000000000000000000 P 406ab3bbe6cd45d5aa86c9884e49ab6e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 406ab3bbe6cd45d5aa86c9884e49ab6e, State: Initialized, Role: FOLLOWER
I20260812 06:19:45.972383 13610 consensus_queue.cc:260] T 00000000000000000000000000000000 P 406ab3bbe6cd45d5aa86c9884e49ab6e [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: "406ab3bbe6cd45d5aa86c9884e49ab6e" member_type: VOTER }
I20260812 06:19:45.972463 13610 raft_consensus.cc:399] T 00000000000000000000000000000000 P 406ab3bbe6cd45d5aa86c9884e49ab6e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:45.972489 13610 raft_consensus.cc:493] T 00000000000000000000000000000000 P 406ab3bbe6cd45d5aa86c9884e49ab6e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:45.972569 13610 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 406ab3bbe6cd45d5aa86c9884e49ab6e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:45.973296 13610 raft_consensus.cc:515] T 00000000000000000000000000000000 P 406ab3bbe6cd45d5aa86c9884e49ab6e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "406ab3bbe6cd45d5aa86c9884e49ab6e" member_type: VOTER }
I20260812 06:19:45.973448 13610 leader_election.cc:304] T 00000000000000000000000000000000 P 406ab3bbe6cd45d5aa86c9884e49ab6e [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: 406ab3bbe6cd45d5aa86c9884e49ab6e; no voters: 
I20260812 06:19:45.973671 13610 leader_election.cc:290] T 00000000000000000000000000000000 P 406ab3bbe6cd45d5aa86c9884e49ab6e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:45.973814 13613 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 406ab3bbe6cd45d5aa86c9884e49ab6e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:45.974078 13613 raft_consensus.cc:697] T 00000000000000000000000000000000 P 406ab3bbe6cd45d5aa86c9884e49ab6e [term 1 LEADER]: Becoming Leader. State: Replica: 406ab3bbe6cd45d5aa86c9884e49ab6e, State: Running, Role: LEADER
I20260812 06:19:45.974212 13613 consensus_queue.cc:237] T 00000000000000000000000000000000 P 406ab3bbe6cd45d5aa86c9884e49ab6e [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: "406ab3bbe6cd45d5aa86c9884e49ab6e" member_type: VOTER }
I20260812 06:19:45.974234 13610 sys_catalog.cc:565] T 00000000000000000000000000000000 P 406ab3bbe6cd45d5aa86c9884e49ab6e [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:45.974664 13614 sys_catalog.cc:455] T 00000000000000000000000000000000 P 406ab3bbe6cd45d5aa86c9884e49ab6e [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "406ab3bbe6cd45d5aa86c9884e49ab6e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "406ab3bbe6cd45d5aa86c9884e49ab6e" member_type: VOTER } }
I20260812 06:19:45.974771 13614 sys_catalog.cc:458] T 00000000000000000000000000000000 P 406ab3bbe6cd45d5aa86c9884e49ab6e [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:45.974854 13615 sys_catalog.cc:455] T 00000000000000000000000000000000 P 406ab3bbe6cd45d5aa86c9884e49ab6e [sys.catalog]: SysCatalogTable state changed. Reason: New leader 406ab3bbe6cd45d5aa86c9884e49ab6e. Latest consensus state: current_term: 1 leader_uuid: "406ab3bbe6cd45d5aa86c9884e49ab6e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "406ab3bbe6cd45d5aa86c9884e49ab6e" member_type: VOTER } }
I20260812 06:19:45.974992 13615 sys_catalog.cc:458] T 00000000000000000000000000000000 P 406ab3bbe6cd45d5aa86c9884e49ab6e [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:45.975466 13617 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:45.976217 13617 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:45.976501 13358 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:45.978091 13617 catalog_manager.cc:1383] Generated new cluster ID: b12ada182d2b4862b526b74f4271f955
I20260812 06:19:45.978160 13617 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:45.995292 13617 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:45.995955 13617 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:46.004333 13617 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 406ab3bbe6cd45d5aa86c9884e49ab6e: Generated new TSK 0
I20260812 06:19:46.004539 13617 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:46.008803 13358 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:46.010718 13631 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:19:46.010891 13634 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:19:46.010867 13632 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:19:46.011030 13358 server_base.cc:1061] running on GCE node
I20260812 06:19:46.011307 13358 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:46.011371 13358 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:19:46.011394 13358 hybrid_clock.cc:648] HybridClock initialized: now 1786515586011394 us; error 0 us; skew 500 ppm
I20260812 06:19:46.012324 13358 webserver.cc:533] Webserver started at http://127.13.11.129:41365/ using document root <none> and password file <none>
I20260812 06:19:46.012506 13358 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:46.012559 13358 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:46.012641 13358 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:46.013058 13358 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/instance:
uuid: "b3423ed01bb24d87a0f3e3feac46e07e"
format_stamp: "Formatted at 2026-08-12 06:19:46 on dist-test-slave-bxbt"
I20260812 06:19:46.014601 13358 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:46.015643 13639 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:19:46.015961 13358 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:46.016055 13358 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root
uuid: "b3423ed01bb24d87a0f3e3feac46e07e"
format_stamp: "Formatted at 2026-08-12 06:19:46 on dist-test-slave-bxbt"
I20260812 06:19:46.016144 13358 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-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:19:46.021298 13358 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:46.021627 13358 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:46.021924 13358 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:46.022380 13358 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:46.022442 13358 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:46.022503 13358 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:46.022539 13358 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:46.026769 13358 rpc_server.cc:307] RPC server started. Bound to: 127.13.11.129:46259
I20260812 06:19:46.026803 13702 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.11.129:46259 every 8 connection(s)
I20260812 06:19:46.035167 13703 heartbeater.cc:344] Connected to a master server at 127.13.11.190:45815
I20260812 06:19:46.035295 13703 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:46.035499 13703 heartbeater.cc:507] Master 127.13.11.190:45815 requested a full tablet report, sending...
I20260812 06:19:46.036207 13574 ts_manager.cc:194] Registered new tserver with Master: b3423ed01bb24d87a0f3e3feac46e07e (127.13.11.129:46259)
I20260812 06:19:46.036240 13358 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008986201s
I20260812 06:19:46.037074 13574 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:42536
I20260812 06:19:46.043612 13574 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:42548:
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:19:46.052539 13667 tablet_service.cc:1511] Processing CreateTablet for tablet 722d4dae69f340daab30af1a8564e043 (DEFAULT_TABLE table=heavy-update-compaction-test [id=900e602c787740d58ebd9cf507999676]), partition=
I20260812 06:19:46.052814 13667 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 722d4dae69f340daab30af1a8564e043. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:46.054682 13715 tablet_bootstrap.cc:492] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Bootstrap starting.
I20260812 06:19:46.055533 13715 tablet_bootstrap.cc:654] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:46.056622 13715 tablet_bootstrap.cc:492] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: No bootstrap required, opened a new log
I20260812 06:19:46.056697 13715 ts_tablet_manager.cc:1403] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.001s
I20260812 06:19:46.057086 13715 raft_consensus.cc:359] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b3423ed01bb24d87a0f3e3feac46e07e" member_type: VOTER last_known_addr { host: "127.13.11.129" port: 46259 } }
I20260812 06:19:46.057205 13715 raft_consensus.cc:385] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:46.057271 13715 raft_consensus.cc:740] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b3423ed01bb24d87a0f3e3feac46e07e, State: Initialized, Role: FOLLOWER
I20260812 06:19:46.057634 13715 consensus_queue.cc:260] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e [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: "b3423ed01bb24d87a0f3e3feac46e07e" member_type: VOTER last_known_addr { host: "127.13.11.129" port: 46259 } }
I20260812 06:19:46.057749 13715 raft_consensus.cc:399] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:46.057804 13715 raft_consensus.cc:493] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:46.057859 13715 raft_consensus.cc:3060] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:46.058561 13715 raft_consensus.cc:515] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b3423ed01bb24d87a0f3e3feac46e07e" member_type: VOTER last_known_addr { host: "127.13.11.129" port: 46259 } }
I20260812 06:19:46.058712 13715 leader_election.cc:304] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e [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: b3423ed01bb24d87a0f3e3feac46e07e; no voters: 
I20260812 06:19:46.058930 13715 leader_election.cc:290] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:46.059062 13717 raft_consensus.cc:2804] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:46.059329 13703 heartbeater.cc:499] Master 127.13.11.190:45815 was elected leader, sending a full tablet report...
I20260812 06:19:46.059302 13715 ts_tablet_manager.cc:1434] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:19:46.059299 13717 raft_consensus.cc:697] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e [term 1 LEADER]: Becoming Leader. State: Replica: b3423ed01bb24d87a0f3e3feac46e07e, State: Running, Role: LEADER
I20260812 06:19:46.059513 13717 consensus_queue.cc:237] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e [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: "b3423ed01bb24d87a0f3e3feac46e07e" member_type: VOTER last_known_addr { host: "127.13.11.129" port: 46259 } }
I20260812 06:19:46.060951 13574 catalog_manager.cc:5719] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e reported cstate change: term changed from 0 to 1, leader changed from <none> to b3423ed01bb24d87a0f3e3feac46e07e (127.13.11.129). New cstate: current_term: 1 leader_uuid: "b3423ed01bb24d87a0f3e3feac46e07e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b3423ed01bb24d87a0f3e3feac46e07e" member_type: VOTER last_known_addr { host: "127.13.11.129" port: 46259 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:46.118717 13358 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.011s	sys 0.012s
I20260812 06:19:46.277694 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushMRSOp(722d4dae69f340daab30af1a8564e043): perf score=19.054940
I20260812 06:19:46.430958 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushMRSOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.153s	user 0.122s	sys 0.028s Metrics: {"bytes_written":13374123,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":106,"dirs.run_cpu_time_us":213,"dirs.run_wall_time_us":843,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40149,"lbm_writes_lt_1ms":783,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":14464,"update_count":1630}
I20260812 06:19:46.431843 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling LogGCOp(722d4dae69f340daab30af1a8564e043): free 20743880 bytes of WAL
I20260812 06:19:46.432114 13644 log_reader.cc:385] T 722d4dae69f340daab30af1a8564e043: removed 2 log segments from log reader
I20260812 06:19:46.432205 13644 log.cc:1079] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/722d4dae69f340daab30af1a8564e043/wal-000000001 (ops 1-6)
I20260812 06:19:46.432263 13644 log.cc:1079] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/722d4dae69f340daab30af1a8564e043/wal-000000002 (ops 7-11)
I20260812 06:19:46.436841 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: LogGCOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.005s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:19:46.437179 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=2.188937
I20260812 06:19:46.456017 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.019s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3446259,"delete_count":0,"lbm_write_time_us":5197,"lbm_writes_lt_1ms":87,"reinsert_count":0,"update_count":420}
I20260812 06:19:46.456497 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=2.188937
I20260812 06:19:46.465653 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.009s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3369,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:46.466104 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling MajorDeltaCompactionOp(722d4dae69f340daab30af1a8564e043): perf score=1.000000
I20260812 06:19:46.630448 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: MajorDeltaCompactionOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.164s	user 0.134s	sys 0.028s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774787,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":406,"lbm_read_time_us":12534,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28899,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5632,"thread_start_us":244,"threads_started":5,"update_count":2500}
I20260812 06:19:46.630967 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling UndoDeltaBlockGCOp(722d4dae69f340daab30af1a8564e043): 16411393 bytes on disk
I20260812 06:19:46.631433 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: UndoDeltaBlockGCOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4}
I20260812 06:19:46.631959 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=11.118625
I20260812 06:19:46.664955 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.033s	user 0.019s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14150,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:46.665493 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=2.188937
I20260812 06:19:46.691577 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.026s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5070,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:46.692067 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=2.188937
I20260812 06:19:46.701836 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3779,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.702250 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling MajorDeltaCompactionOp(722d4dae69f340daab30af1a8564e043): perf score=1.000000
I20260812 06:19:46.859884 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: MajorDeltaCompactionOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.157s	user 0.133s	sys 0.024s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":656,"lbm_read_time_us":10501,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30032,"lbm_writes_lt_1ms":543,"mutex_wait_us":273,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":26496,"update_count":2500}
I20260812 06:19:46.860909 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=10.126437
I20260812 06:19:46.891986 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.031s	user 0.027s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13582,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:46.892510 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=2.188937
I20260812 06:19:46.902554 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3800,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.902968 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling MajorDeltaCompactionOp(722d4dae69f340daab30af1a8564e043): perf score=1.000000
I20260812 06:19:47.024231 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: MajorDeltaCompactionOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.121s	user 0.097s	sys 0.024s 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":216,"lbm_read_time_us":8467,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23505,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2000}
I20260812 06:19:47.024899 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=10.126437
I20260812 06:19:47.076610 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.052s	user 0.024s	sys 0.020s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14513,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:47.077162 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=2.188937
I20260812 06:19:47.092746 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6138,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.093151 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling MajorDeltaCompactionOp(722d4dae69f340daab30af1a8564e043): perf score=1.000000
I20260812 06:19:47.244659 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: MajorDeltaCompactionOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.151s	user 0.111s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":304,"lbm_read_time_us":10713,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24189,"lbm_writes_lt_1ms":443,"mutex_wait_us":66,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2000}
I20260812 06:19:47.245229 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=10.126437
I20260812 06:19:47.293856 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.048s	user 0.017s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17597,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:47.294348 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=2.188937
I20260812 06:19:47.304354 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3940,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.304742 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling MajorDeltaCompactionOp(722d4dae69f340daab30af1a8564e043): perf score=1.000000
I20260812 06:19:47.437700 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: MajorDeltaCompactionOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.133s	user 0.116s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":858,"lbm_read_time_us":9595,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24388,"lbm_writes_lt_1ms":443,"mutex_wait_us":299,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4736,"update_count":2000}
I20260812 06:19:47.438397 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=10.126437
I20260812 06:19:47.475574 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.037s	user 0.024s	sys 0.008s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14863,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:47.476123 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=2.188937
I20260812 06:19:47.486617 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3966,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.487412 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling MajorDeltaCompactionOp(722d4dae69f340daab30af1a8564e043): perf score=1.000000
I20260812 06:19:47.610918 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: MajorDeltaCompactionOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.123s	user 0.111s	sys 0.012s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":296,"lbm_read_time_us":8917,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22651,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":2000}
I20260812 06:19:47.611447 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=10.126437
I20260812 06:19:47.654285 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.043s	user 0.018s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14131,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:47.654793 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=2.188937
I20260812 06:19:47.665518 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3986,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.666198 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushMRSOp(722d4dae69f340daab30af1a8564e043): perf score=1.000000
I20260812 06:19:47.695084 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushMRSOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.029s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":345,"dirs.run_wall_time_us":1371,"drs_written":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1913,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:47.695873 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling LogGCOp(722d4dae69f340daab30af1a8564e043): free 120553332 bytes of WAL
I20260812 06:19:47.696113 13644 log_reader.cc:385] T 722d4dae69f340daab30af1a8564e043: removed 12 log segments from log reader
I20260812 06:19:47.696178 13644 log.cc:1079] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/722d4dae69f340daab30af1a8564e043/wal-000000003 (ops 12-16)
I20260812 06:19:47.696233 13644 log.cc:1079] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/722d4dae69f340daab30af1a8564e043/wal-000000004 (ops 17-21)
I20260812 06:19:47.696291 13644 log.cc:1079] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/722d4dae69f340daab30af1a8564e043/wal-000000005 (ops 22-26)
I20260812 06:19:47.696332 13644 log.cc:1079] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/722d4dae69f340daab30af1a8564e043/wal-000000006 (ops 27-31)
I20260812 06:19:47.696368 13644 log.cc:1079] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/722d4dae69f340daab30af1a8564e043/wal-000000007 (ops 32-36)
I20260812 06:19:47.696403 13644 log.cc:1079] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/722d4dae69f340daab30af1a8564e043/wal-000000008 (ops 37-41)
I20260812 06:19:47.696439 13644 log.cc:1079] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/722d4dae69f340daab30af1a8564e043/wal-000000009 (ops 42-46)
I20260812 06:19:47.696475 13644 log.cc:1079] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/722d4dae69f340daab30af1a8564e043/wal-000000010 (ops 47-50)
I20260812 06:19:47.696530 13644 log.cc:1079] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/722d4dae69f340daab30af1a8564e043/wal-000000011 (ops 51-55)
I20260812 06:19:47.696568 13644 log.cc:1079] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/722d4dae69f340daab30af1a8564e043/wal-000000012 (ops 56-60)
I20260812 06:19:47.696605 13644 log.cc:1079] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/722d4dae69f340daab30af1a8564e043/wal-000000013 (ops 61-64)
I20260812 06:19:47.696643 13644 log.cc:1079] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/722d4dae69f340daab30af1a8564e043/wal-000000014 (ops 65-69)
I20260812 06:19:47.720991 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: LogGCOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.025s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:19:47.721602 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=3.181125
I20260812 06:19:47.733688 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4483,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:47.734165 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=2.188937
I20260812 06:19:47.748528 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.014s	user 0.006s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5370,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:47.749150 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling MajorDeltaCompactionOp(722d4dae69f340daab30af1a8564e043): perf score=1.000000
I20260812 06:19:47.923982 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: MajorDeltaCompactionOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.175s	user 0.138s	sys 0.036s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":440,"lbm_read_time_us":13955,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34952,"lbm_writes_lt_1ms":643,"mutex_wait_us":37,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9472,"thread_start_us":74,"threads_started":1,"update_count":3000}
I20260812 06:19:47.926368 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling UndoDeltaBlockGCOp(722d4dae69f340daab30af1a8564e043): 472 bytes on disk
I20260812 06:19:47.926865 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: UndoDeltaBlockGCOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:19:47.927399 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=14.095187
I20260812 06:19:47.977869 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.050s	user 0.024s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20094,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:47.978430 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=2.188937
I20260812 06:19:47.989085 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3992,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.989629 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling MajorDeltaCompactionOp(722d4dae69f340daab30af1a8564e043): perf score=1.000000
I20260812 06:19:48.150174 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: MajorDeltaCompactionOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.160s	user 0.121s	sys 0.037s 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":207,"lbm_read_time_us":10065,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30905,"lbm_writes_lt_1ms":543,"mutex_wait_us":77,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2500}
I20260812 06:19:48.150802 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=12.110812
I20260812 06:19:48.181032 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.030s	user 0.013s	sys 0.016s Metrics: {"bytes_written":13579241,"delete_count":0,"lbm_write_time_us":13504,"lbm_writes_lt_1ms":334,"reinsert_count":0,"update_count":1655}
I20260812 06:19:48.181869 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=1.196750
I20260812 06:19:48.194340 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":2830880,"delete_count":0,"lbm_write_time_us":4608,"lbm_writes_lt_1ms":72,"reinsert_count":0,"update_count":345}
I20260812 06:19:48.194861 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling MajorDeltaCompactionOp(722d4dae69f340daab30af1a8564e043): perf score=1.000000
I20260812 06:19:48.348239 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: MajorDeltaCompactionOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.153s	user 0.107s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672249,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":707,"lbm_read_time_us":10975,"lbm_reads_lt_1ms":468,"lbm_write_time_us":24573,"lbm_writes_lt_1ms":443,"mutex_wait_us":2304,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11136,"update_count":2000}
I20260812 06:19:48.349089 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=10.126437
I20260812 06:19:48.384460 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.035s	user 0.029s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13999,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:48.384986 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=2.188937
I20260812 06:19:48.409497 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.024s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5346,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.410156 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=2.188937
I20260812 06:19:48.429396 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.019s	user 0.010s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4000,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.429961 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling MajorDeltaCompactionOp(722d4dae69f340daab30af1a8564e043): perf score=1.000000
I20260812 06:19:48.617388 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: MajorDeltaCompactionOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.187s	user 0.129s	sys 0.056s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774808,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":270,"lbm_read_time_us":11859,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31380,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:48.618072 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=14.095187
I20260812 06:19:48.672544 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.054s	user 0.023s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23062,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:48.673066 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=2.188937
I20260812 06:19:48.684723 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.011s	user 0.006s	sys 0.004s 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:19:48.685195 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling MajorDeltaCompactionOp(722d4dae69f340daab30af1a8564e043): perf score=1.000000
I20260812 06:19:48.860693 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: MajorDeltaCompactionOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.175s	user 0.121s	sys 0.051s 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":742,"lbm_read_time_us":11664,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29148,"lbm_writes_lt_1ms":543,"mutex_wait_us":298,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9216,"update_count":2500}
I20260812 06:19:48.864025 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=14.095187
I20260812 06:19:48.918711 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.054s	user 0.034s	sys 0.016s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":27878,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:19:48.919231 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=2.188937
I20260812 06:19:48.930724 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4250,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.931180 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling MajorDeltaCompactionOp(722d4dae69f340daab30af1a8564e043): perf score=1.000000
I20260812 06:19:49.098840 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: MajorDeltaCompactionOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.167s	user 0.105s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":166,"lbm_read_time_us":10124,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32558,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14976,"update_count":2500}
I20260812 06:19:49.099572 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=14.095187
I20260812 06:19:49.148175 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.048s	user 0.020s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20779,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:49.148684 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=2.188937
I20260812 06:19:49.162484 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.014s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5036,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.162995 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushMRSOp(722d4dae69f340daab30af1a8564e043): perf score=1.000000
I20260812 06:19:49.198799 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushMRSOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.036s	user 0.030s	sys 0.003s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":246,"dirs.run_wall_time_us":1237,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2057,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:49.199712 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling LogGCOp(722d4dae69f340daab30af1a8564e043): free 133024392 bytes of WAL
I20260812 06:19:49.199965 13644 log_reader.cc:385] T 722d4dae69f340daab30af1a8564e043: removed 13 log segments from log reader
I20260812 06:19:49.200050 13644 log.cc:1079] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/722d4dae69f340daab30af1a8564e043/wal-000000015 (ops 70-74)
I20260812 06:19:49.200109 13644 log.cc:1079] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/722d4dae69f340daab30af1a8564e043/wal-000000016 (ops 75-79)
I20260812 06:19:49.200148 13644 log.cc:1079] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/722d4dae69f340daab30af1a8564e043/wal-000000017 (ops 80-84)
I20260812 06:19:49.200212 13644 log.cc:1079] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/722d4dae69f340daab30af1a8564e043/wal-000000018 (ops 85-89)
I20260812 06:19:49.200255 13644 log.cc:1079] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/722d4dae69f340daab30af1a8564e043/wal-000000019 (ops 90-94)
I20260812 06:19:49.200296 13644 log.cc:1079] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/722d4dae69f340daab30af1a8564e043/wal-000000020 (ops 95-98)
I20260812 06:19:49.200335 13644 log.cc:1079] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/722d4dae69f340daab30af1a8564e043/wal-000000021 (ops 99-103)
I20260812 06:19:49.200378 13644 log.cc:1079] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/722d4dae69f340daab30af1a8564e043/wal-000000022 (ops 104-108)
I20260812 06:19:49.200423 13644 log.cc:1079] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/722d4dae69f340daab30af1a8564e043/wal-000000023 (ops 109-113)
I20260812 06:19:49.200464 13644 log.cc:1079] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/722d4dae69f340daab30af1a8564e043/wal-000000024 (ops 114-118)
I20260812 06:19:49.200510 13644 log.cc:1079] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/722d4dae69f340daab30af1a8564e043/wal-000000025 (ops 119-122)
I20260812 06:19:49.200552 13644 log.cc:1079] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/722d4dae69f340daab30af1a8564e043/wal-000000026 (ops 123-127)
I20260812 06:19:49.200601 13644 log.cc:1079] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/722d4dae69f340daab30af1a8564e043/wal-000000027 (ops 128-133)
I20260812 06:19:49.231189 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: LogGCOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.031s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:19:49.231622 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=5.165500
I20260812 06:19:49.263912 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.032s	user 0.008s	sys 0.024s Metrics: {"bytes_written":6482066,"delete_count":0,"lbm_write_time_us":8665,"lbm_writes_lt_1ms":161,"reinsert_count":0,"update_count":790}
I20260812 06:19:49.264523 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=1.000000
I20260812 06:19:49.274610 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":1723202,"delete_count":0,"lbm_write_time_us":3080,"lbm_writes_lt_1ms":45,"reinsert_count":0,"update_count":210}
I20260812 06:19:49.275202 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling MajorDeltaCompactionOp(722d4dae69f340daab30af1a8564e043): perf score=1.000000
I20260812 06:19:49.508482 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: MajorDeltaCompactionOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.233s	user 0.141s	sys 0.079s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979694,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":640,"lbm_read_time_us":14580,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39192,"lbm_writes_lt_1ms":743,"mutex_wait_us":508,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":17536,"thread_start_us":75,"threads_started":1,"update_count":3500}
I20260812 06:19:49.509228 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=18.063937
I20260812 06:19:49.570308 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.061s	user 0.041s	sys 0.012s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":25090,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:49.570837 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling UndoDeltaBlockGCOp(722d4dae69f340daab30af1a8564e043): 493 bytes on disk
I20260812 06:19:49.571231 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: UndoDeltaBlockGCOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:19:49.571802 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=2.188937
I20260812 06:19:49.582532 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4099,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.583307 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling MajorDeltaCompactionOp(722d4dae69f340daab30af1a8564e043): perf score=1.000000
I20260812 06:19:49.787839 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: MajorDeltaCompactionOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.204s	user 0.127s	sys 0.076s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877105,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":234,"lbm_read_time_us":14361,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33566,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:19:49.788533 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=14.095187
I20260812 06:19:49.844982 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.056s	user 0.032s	sys 0.018s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22862,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:49.845580 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=2.188937
I20260812 06:19:49.857682 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5193,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.858628 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling MajorDeltaCompactionOp(722d4dae69f340daab30af1a8564e043): perf score=1.000000
I20260812 06:19:50.014227 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: MajorDeltaCompactionOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.155s	user 0.093s	sys 0.060s 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":116,"lbm_read_time_us":9665,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25761,"lbm_writes_lt_1ms":543,"mutex_wait_us":3,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12032,"update_count":2500}
I20260812 06:19:50.014838 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=14.095187
I20260812 06:19:50.069941 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.055s	user 0.036s	sys 0.003s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":17740,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:50.070511 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=2.188937
I20260812 06:19:50.089489 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.019s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":7020,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.089934 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling MajorDeltaCompactionOp(722d4dae69f340daab30af1a8564e043): perf score=1.000000
I20260812 06:19:50.256279 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: MajorDeltaCompactionOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.166s	user 0.102s	sys 0.064s 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":142,"lbm_read_time_us":10884,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28184,"lbm_writes_lt_1ms":543,"mutex_wait_us":38,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6912,"update_count":2500}
I20260812 06:19:50.257014 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=14.095187
I20260812 06:19:50.320500 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.063s	user 0.039s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22552,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:50.321062 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=2.188937
I20260812 06:19:50.333683 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.012s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4635,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.334220 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling MajorDeltaCompactionOp(722d4dae69f340daab30af1a8564e043): perf score=1.000000
I20260812 06:19:50.507650 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: MajorDeltaCompactionOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.172s	user 0.117s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":486,"lbm_read_time_us":11138,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27898,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9088,"update_count":2500}
I20260812 06:19:50.508621 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=14.095187
I20260812 06:19:50.563735 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.055s	user 0.020s	sys 0.035s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":26819,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:50.564332 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=2.188937
I20260812 06:19:50.581689 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.017s	user 0.002s	sys 0.007s 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:19:50.582484 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushMRSOp(722d4dae69f340daab30af1a8564e043): perf score=1.000000
I20260812 06:19:50.622255 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushMRSOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.040s	user 0.024s	sys 0.000s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":276,"dirs.run_wall_time_us":1432,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1752,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:50.623919 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=3.181125
I20260812 06:19:50.637600 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.014s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4348804,"delete_count":0,"lbm_write_time_us":4323,"lbm_writes_lt_1ms":109,"reinsert_count":0,"update_count":530}
I20260812 06:19:50.638032 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling LogGCOp(722d4dae69f340daab30af1a8564e043): free 120553644 bytes of WAL
I20260812 06:19:50.638227 13644 log_reader.cc:385] T 722d4dae69f340daab30af1a8564e043: removed 12 log segments from log reader
I20260812 06:19:50.638283 13644 log.cc:1079] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/722d4dae69f340daab30af1a8564e043/wal-000000028 (ops 134-138)
I20260812 06:19:50.638322 13644 log.cc:1079] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/722d4dae69f340daab30af1a8564e043/wal-000000029 (ops 139-142)
I20260812 06:19:50.638358 13644 log.cc:1079] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/722d4dae69f340daab30af1a8564e043/wal-000000030 (ops 143-147)
I20260812 06:19:50.638389 13644 log.cc:1079] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/722d4dae69f340daab30af1a8564e043/wal-000000031 (ops 148-152)
I20260812 06:19:50.638418 13644 log.cc:1079] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/722d4dae69f340daab30af1a8564e043/wal-000000032 (ops 153-156)
I20260812 06:19:50.638446 13644 log.cc:1079] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/722d4dae69f340daab30af1a8564e043/wal-000000033 (ops 157-161)
I20260812 06:19:50.638478 13644 log.cc:1079] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/722d4dae69f340daab30af1a8564e043/wal-000000034 (ops 162-166)
I20260812 06:19:50.638513 13644 log.cc:1079] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/722d4dae69f340daab30af1a8564e043/wal-000000035 (ops 167-171)
I20260812 06:19:50.638543 13644 log.cc:1079] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/722d4dae69f340daab30af1a8564e043/wal-000000036 (ops 172-176)
I20260812 06:19:50.638573 13644 log.cc:1079] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/722d4dae69f340daab30af1a8564e043/wal-000000037 (ops 177-181)
I20260812 06:19:50.638602 13644 log.cc:1079] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/722d4dae69f340daab30af1a8564e043/wal-000000038 (ops 182-186)
I20260812 06:19:50.638631 13644 log.cc:1079] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: Deleting log segment in path: /tmp/dist-test-taskaTFtz3/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515580595216-13358-0/minicluster-data/ts-0-root/wals/722d4dae69f340daab30af1a8564e043/wal-000000039 (ops 187-191)
I20260812 06:19:50.667106 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: LogGCOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:50.667616 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=2.188937
I20260812 06:19:50.692529 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.025s	user 0.001s	sys 0.010s Metrics: {"bytes_written":3856508,"delete_count":0,"lbm_write_time_us":4579,"lbm_writes_lt_1ms":97,"reinsert_count":0,"update_count":470}
I20260812 06:19:50.693080 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling UndoDeltaBlockGCOp(722d4dae69f340daab30af1a8564e043): 446 bytes on disk
I20260812 06:19:50.693506 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: UndoDeltaBlockGCOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:19:50.694147 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=2.188937
I20260812 06:19:50.704285 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3935,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.704716 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling MajorDeltaCompactionOp(722d4dae69f340daab30af1a8564e043): perf score=1.000000
I20260812 06:19:50.876672 13358 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.758s	user 1.739s	sys 0.180s
I20260812 06:19:50.933863 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: MajorDeltaCompactionOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.229s	user 0.140s	sys 0.087s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37082276,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"lbm_read_time_us":16036,"lbm_reads_lt_1ms":871,"lbm_write_time_us":43128,"lbm_writes_lt_1ms":843,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":4000}
I20260812 06:19:50.934333 13704 maintenance_manager.cc:419] P b3423ed01bb24d87a0f3e3feac46e07e: Scheduling FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043): perf score=14.095187
I20260812 06:19:50.965258 13358 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.088s	user 0.001s	sys 0.000s
I20260812 06:19:50.965758 13358 tablet_server.cc:179] TabletServer@127.13.11.129:0 shutting down...
I20260812 06:19:50.975492 13644 maintenance_manager.cc:643] P b3423ed01bb24d87a0f3e3feac46e07e: FlushDeltaMemStoresOp(722d4dae69f340daab30af1a8564e043) complete. Timing: real 0.041s	user 0.021s	sys 0.016s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":17928,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:50.976016 13358 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:50.976367 13358 tablet_replica.cc:333] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e: stopping tablet replica
I20260812 06:19:50.976475 13358 raft_consensus.cc:2243] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:50.976599 13358 raft_consensus.cc:2272] T 722d4dae69f340daab30af1a8564e043 P b3423ed01bb24d87a0f3e3feac46e07e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:50.991035 13358 tablet_server.cc:196] TabletServer@127.13.11.129:0 shutdown complete.
I20260812 06:19:51.019506 13358 master.cc:562] Master@127.13.11.190:45815 shutting down...
I20260812 06:19:51.023801 13358 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 406ab3bbe6cd45d5aa86c9884e49ab6e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:51.023963 13358 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 406ab3bbe6cd45d5aa86c9884e49ab6e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:51.024015 13358 tablet_replica.cc:333] T 00000000000000000000000000000000 P 406ab3bbe6cd45d5aa86c9884e49ab6e: stopping tablet replica
I20260812 06:19:51.036309 13358 master.cc:584] Master@127.13.11.190:45815 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5215 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10514 ms total)

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