[==========] 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:55.297456 17185 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.16.200.126:36635
I20260812 06:19:55.298383 17185 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:55.298924 17185 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:55.305248 17193 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:55.305321 17185 server_base.cc:1061] running on GCE node
W20260812 06:19:55.305261 17195 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:55.305567 17191 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:55.306085 17185 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:55.306205 17185 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:55.306250 17185 hybrid_clock.cc:648] HybridClock initialized: now 1786515595306248 us; error 0 us; skew 500 ppm
I20260812 06:19:55.308079 17185 webserver.cc:533] Webserver started at http://127.16.200.126:38185/ using document root <none> and password file <none>
I20260812 06:19:55.308635 17185 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:55.308703 17185 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:55.308954 17185 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:55.310722 17185 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/master-0-root/instance:
uuid: "d0862ac119764046b89874b6d7a07055"
format_stamp: "Formatted at 2026-08-12 06:19:55 on dist-test-slave-6bbx"
I20260812 06:19:55.314316 17185 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:19:55.316385 17209 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:55.317353 17185 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:55.317456 17185 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/master-0-root
uuid: "d0862ac119764046b89874b6d7a07055"
format_stamp: "Formatted at 2026-08-12 06:19:55 on dist-test-slave-6bbx"
I20260812 06:19:55.317549 17185 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-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:55.327345 17185 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:55.327896 17185 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:55.328035 17185 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:55.334890 17321 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.16.200.126:36635 every 8 connection(s)
I20260812 06:19:55.334892 17185 rpc_server.cc:307] RPC server started. Bound to: 127.16.200.126:36635
I20260812 06:19:55.337024 17322 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:55.342108 17322 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P d0862ac119764046b89874b6d7a07055: Bootstrap starting.
I20260812 06:19:55.344363 17322 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P d0862ac119764046b89874b6d7a07055: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:55.345206 17322 log.cc:826] T 00000000000000000000000000000000 P d0862ac119764046b89874b6d7a07055: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:55.346782 17322 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P d0862ac119764046b89874b6d7a07055: No bootstrap required, opened a new log
I20260812 06:19:55.349419 17322 raft_consensus.cc:359] T 00000000000000000000000000000000 P d0862ac119764046b89874b6d7a07055 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d0862ac119764046b89874b6d7a07055" member_type: VOTER }
I20260812 06:19:55.349570 17322 raft_consensus.cc:385] T 00000000000000000000000000000000 P d0862ac119764046b89874b6d7a07055 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:55.349633 17322 raft_consensus.cc:740] T 00000000000000000000000000000000 P d0862ac119764046b89874b6d7a07055 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: d0862ac119764046b89874b6d7a07055, State: Initialized, Role: FOLLOWER
I20260812 06:19:55.350179 17322 consensus_queue.cc:260] T 00000000000000000000000000000000 P d0862ac119764046b89874b6d7a07055 [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: "d0862ac119764046b89874b6d7a07055" member_type: VOTER }
I20260812 06:19:55.350314 17322 raft_consensus.cc:399] T 00000000000000000000000000000000 P d0862ac119764046b89874b6d7a07055 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:55.350378 17322 raft_consensus.cc:493] T 00000000000000000000000000000000 P d0862ac119764046b89874b6d7a07055 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:55.350497 17322 raft_consensus.cc:3060] T 00000000000000000000000000000000 P d0862ac119764046b89874b6d7a07055 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:55.351194 17322 raft_consensus.cc:515] T 00000000000000000000000000000000 P d0862ac119764046b89874b6d7a07055 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d0862ac119764046b89874b6d7a07055" member_type: VOTER }
I20260812 06:19:55.351583 17322 leader_election.cc:304] T 00000000000000000000000000000000 P d0862ac119764046b89874b6d7a07055 [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: d0862ac119764046b89874b6d7a07055; no voters: 
I20260812 06:19:55.351874 17322 leader_election.cc:290] T 00000000000000000000000000000000 P d0862ac119764046b89874b6d7a07055 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:55.351989 17330 raft_consensus.cc:2804] T 00000000000000000000000000000000 P d0862ac119764046b89874b6d7a07055 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:55.352196 17330 raft_consensus.cc:697] T 00000000000000000000000000000000 P d0862ac119764046b89874b6d7a07055 [term 1 LEADER]: Becoming Leader. State: Replica: d0862ac119764046b89874b6d7a07055, State: Running, Role: LEADER
I20260812 06:19:55.352581 17330 consensus_queue.cc:237] T 00000000000000000000000000000000 P d0862ac119764046b89874b6d7a07055 [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: "d0862ac119764046b89874b6d7a07055" member_type: VOTER }
I20260812 06:19:55.352751 17322 sys_catalog.cc:565] T 00000000000000000000000000000000 P d0862ac119764046b89874b6d7a07055 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:55.354271 17331 sys_catalog.cc:455] T 00000000000000000000000000000000 P d0862ac119764046b89874b6d7a07055 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "d0862ac119764046b89874b6d7a07055" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d0862ac119764046b89874b6d7a07055" member_type: VOTER } }
I20260812 06:19:55.354259 17332 sys_catalog.cc:455] T 00000000000000000000000000000000 P d0862ac119764046b89874b6d7a07055 [sys.catalog]: SysCatalogTable state changed. Reason: New leader d0862ac119764046b89874b6d7a07055. Latest consensus state: current_term: 1 leader_uuid: "d0862ac119764046b89874b6d7a07055" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d0862ac119764046b89874b6d7a07055" member_type: VOTER } }
I20260812 06:19:55.354396 17332 sys_catalog.cc:458] T 00000000000000000000000000000000 P d0862ac119764046b89874b6d7a07055 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:55.354396 17331 sys_catalog.cc:458] T 00000000000000000000000000000000 P d0862ac119764046b89874b6d7a07055 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:55.354789 17350 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:55.354884 17185 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:55.356891 17350 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:55.360981 17350 catalog_manager.cc:1383] Generated new cluster ID: e262c0418f574b4f920840edc344669b
I20260812 06:19:55.361043 17350 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:55.375033 17350 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:55.376190 17350 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:55.386128 17350 catalog_manager.cc:6092] T 00000000000000000000000000000000 P d0862ac119764046b89874b6d7a07055: Generated new TSK 0
I20260812 06:19:55.386848 17350 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:55.419535 17185 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:55.422075 17364 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:55.422176 17365 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:55.422083 17369 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:55.422415 17185 server_base.cc:1061] running on GCE node
I20260812 06:19:55.422580 17185 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:55.422619 17185 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:55.422633 17185 hybrid_clock.cc:648] HybridClock initialized: now 1786515595422634 us; error 0 us; skew 500 ppm
I20260812 06:19:55.423462 17185 webserver.cc:533] Webserver started at http://127.16.200.65:41979/ using document root <none> and password file <none>
I20260812 06:19:55.423623 17185 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:55.423691 17185 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:55.423769 17185 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:55.424100 17185 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root/instance:
uuid: "901411e8a2e04086b7164ddd90a992f6"
format_stamp: "Formatted at 2026-08-12 06:19:55 on dist-test-slave-6bbx"
I20260812 06:19:55.425465 17185 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:55.426366 17374 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:55.426586 17185 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:55.426654 17185 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root
uuid: "901411e8a2e04086b7164ddd90a992f6"
format_stamp: "Formatted at 2026-08-12 06:19:55 on dist-test-slave-6bbx"
I20260812 06:19:55.426725 17185 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-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:55.436102 17185 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:55.436481 17185 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:55.436918 17185 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:55.437731 17185 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:55.437783 17185 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:55.437827 17185 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:55.437857 17185 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:55.444015 17185 rpc_server.cc:307] RPC server started. Bound to: 127.16.200.65:34105
I20260812 06:19:55.444052 17479 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.16.200.65:34105 every 8 connection(s)
I20260812 06:19:55.453516 17480 heartbeater.cc:344] Connected to a master server at 127.16.200.126:36635
I20260812 06:19:55.453751 17480 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:55.454198 17480 heartbeater.cc:507] Master 127.16.200.126:36635 requested a full tablet report, sending...
I20260812 06:19:55.455569 17245 ts_manager.cc:194] Registered new tserver with Master: 901411e8a2e04086b7164ddd90a992f6 (127.16.200.65:34105)
I20260812 06:19:55.455816 17185 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011225022s
I20260812 06:19:55.457036 17245 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:49544
I20260812 06:19:55.464982 17245 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:49558:
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:55.478379 17416 tablet_service.cc:1511] Processing CreateTablet for tablet f94ee07bf1694561aea4b8e3cde01156 (DEFAULT_TABLE table=heavy-update-compaction-test [id=78d096e816154bee92d739ddbe6c4ed0]), partition=
I20260812 06:19:55.478855 17416 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet f94ee07bf1694561aea4b8e3cde01156. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:55.481194 17501 tablet_bootstrap.cc:492] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Bootstrap starting.
I20260812 06:19:55.482342 17501 tablet_bootstrap.cc:654] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:55.483384 17501 tablet_bootstrap.cc:492] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: No bootstrap required, opened a new log
I20260812 06:19:55.483465 17501 ts_tablet_manager.cc:1403] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:55.484122 17501 raft_consensus.cc:359] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "901411e8a2e04086b7164ddd90a992f6" member_type: VOTER last_known_addr { host: "127.16.200.65" port: 34105 } }
I20260812 06:19:55.484228 17501 raft_consensus.cc:385] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:55.484252 17501 raft_consensus.cc:740] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 901411e8a2e04086b7164ddd90a992f6, State: Initialized, Role: FOLLOWER
I20260812 06:19:55.484368 17501 consensus_queue.cc:260] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6 [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: "901411e8a2e04086b7164ddd90a992f6" member_type: VOTER last_known_addr { host: "127.16.200.65" port: 34105 } }
I20260812 06:19:55.484438 17501 raft_consensus.cc:399] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:55.484475 17501 raft_consensus.cc:493] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:55.484524 17501 raft_consensus.cc:3060] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:55.485216 17501 raft_consensus.cc:515] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "901411e8a2e04086b7164ddd90a992f6" member_type: VOTER last_known_addr { host: "127.16.200.65" port: 34105 } }
I20260812 06:19:55.485332 17501 leader_election.cc:304] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6 [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: 901411e8a2e04086b7164ddd90a992f6; no voters: 
I20260812 06:19:55.485566 17501 leader_election.cc:290] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:55.485680 17504 raft_consensus.cc:2804] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:55.485929 17504 raft_consensus.cc:697] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6 [term 1 LEADER]: Becoming Leader. State: Replica: 901411e8a2e04086b7164ddd90a992f6, State: Running, Role: LEADER
I20260812 06:19:55.486032 17501 ts_tablet_manager.cc:1434] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:55.486105 17504 consensus_queue.cc:237] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6 [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: "901411e8a2e04086b7164ddd90a992f6" member_type: VOTER last_known_addr { host: "127.16.200.65" port: 34105 } }
I20260812 06:19:55.486482 17480 heartbeater.cc:499] Master 127.16.200.126:36635 was elected leader, sending a full tablet report...
I20260812 06:19:55.488731 17245 catalog_manager.cc:5719] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6 reported cstate change: term changed from 0 to 1, leader changed from <none> to 901411e8a2e04086b7164ddd90a992f6 (127.16.200.65). New cstate: current_term: 1 leader_uuid: "901411e8a2e04086b7164ddd90a992f6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "901411e8a2e04086b7164ddd90a992f6" member_type: VOTER last_known_addr { host: "127.16.200.65" port: 34105 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:55.550343 17185 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.051s	user 0.017s	sys 0.007s
I20260812 06:19:55.694999 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushMRSOp(f94ee07bf1694561aea4b8e3cde01156): perf score=19.054940
I20260812 06:19:55.902812 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushMRSOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.207s	user 0.141s	sys 0.055s Metrics: {"bytes_written":16861168,"cfile_init":1,"compiler_manager_pool.queue_time_us":178,"delete_count":0,"dirs.queue_time_us":95,"dirs.run_cpu_time_us":269,"dirs.run_wall_time_us":3979,"drs_written":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4,"lbm_write_time_us":47580,"lbm_writes_lt_1ms":878,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":335616,"thread_start_us":87,"threads_started":1,"update_count":2055}
I20260812 06:19:55.904122 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling LogGCOp(f94ee07bf1694561aea4b8e3cde01156): free 20743880 bytes of WAL
I20260812 06:19:55.904448 17384 log_reader.cc:385] T f94ee07bf1694561aea4b8e3cde01156: removed 2 log segments from log reader
I20260812 06:19:55.904521 17384 log.cc:1079] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/f94ee07bf1694561aea4b8e3cde01156/wal-000000001 (ops 1-6)
I20260812 06:19:55.904632 17384 log.cc:1079] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/f94ee07bf1694561aea4b8e3cde01156/wal-000000002 (ops 7-11)
I20260812 06:19:55.909821 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: LogGCOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.006s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:19:55.910216 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling UndoDeltaBlockGCOp(f94ee07bf1694561aea4b8e3cde01156): 16821647 bytes on disk
I20260812 06:19:55.910861 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: UndoDeltaBlockGCOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4}
I20260812 06:19:55.911240 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=6.157687
I20260812 06:19:55.933159 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.022s	user 0.008s	sys 0.011s Metrics: {"bytes_written":7343573,"delete_count":0,"lbm_write_time_us":8397,"lbm_writes_lt_1ms":182,"reinsert_count":0,"update_count":895}
I20260812 06:19:55.933668 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling MajorDeltaCompactionOp(f94ee07bf1694561aea4b8e3cde01156): perf score=1.000000
I20260812 06:19:56.112398 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: MajorDeltaCompactionOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.179s	user 0.143s	sys 0.036s Metrics: {"cfile_cache_miss":622,"cfile_cache_miss_bytes":28507858,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":463,"lbm_read_time_us":11230,"lbm_reads_lt_1ms":654,"lbm_write_time_us":32428,"lbm_writes_lt_1ms":633,"mutex_wait_us":48,"peak_mem_usage":74091738,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":297,"threads_started":5,"update_count":2950}
I20260812 06:19:56.112847 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=14.095187
I20260812 06:19:56.166638 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.054s	user 0.029s	sys 0.016s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":20602,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:56.167157 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=2.188937
I20260812 06:19:56.176851 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3508,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.177373 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling MajorDeltaCompactionOp(f94ee07bf1694561aea4b8e3cde01156): perf score=1.000000
I20260812 06:19:56.343389 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: MajorDeltaCompactionOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.166s	user 0.111s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815680,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":115,"lbm_read_time_us":10911,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28299,"lbm_writes_lt_1ms":543,"mutex_wait_us":53,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":2500}
I20260812 06:19:56.343964 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=14.095187
I20260812 06:19:56.399501 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.055s	user 0.034s	sys 0.011s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18474,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:56.400147 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=2.188937
I20260812 06:19:56.415817 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.015s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5886,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.416328 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling MajorDeltaCompactionOp(f94ee07bf1694561aea4b8e3cde01156): perf score=1.000000
I20260812 06:19:56.581372 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: MajorDeltaCompactionOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.165s	user 0.115s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":488,"lbm_read_time_us":12468,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26338,"lbm_writes_lt_1ms":543,"mutex_wait_us":217,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2500}
I20260812 06:19:56.581820 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=11.118625
I20260812 06:19:56.618608 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.037s	user 0.022s	sys 0.012s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":15495,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:56.619299 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=2.188937
I20260812 06:19:56.650120 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.030s	user 0.005s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5304,"lbm_writes_lt_1ms":93,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":450}
I20260812 06:19:56.650765 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=2.188937
I20260812 06:19:56.666417 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5628,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.667021 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling MajorDeltaCompactionOp(f94ee07bf1694561aea4b8e3cde01156): perf score=1.000000
I20260812 06:19:56.826480 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: MajorDeltaCompactionOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.159s	user 0.135s	sys 0.021s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":967,"lbm_read_time_us":10709,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27153,"lbm_writes_lt_1ms":543,"mutex_wait_us":271,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":24320,"update_count":2500}
I20260812 06:19:56.827080 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=11.118625
I20260812 06:19:56.857030 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.030s	user 0.017s	sys 0.011s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":12044,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:56.857640 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=2.188937
I20260812 06:19:56.871137 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.013s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4182,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:56.871726 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling MajorDeltaCompactionOp(f94ee07bf1694561aea4b8e3cde01156): perf score=1.000000
I20260812 06:19:56.996445 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: MajorDeltaCompactionOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.125s	user 0.099s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713264,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":171,"lbm_read_time_us":8698,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23543,"lbm_writes_lt_1ms":443,"mutex_wait_us":58,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:19:56.997490 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=10.126437
I20260812 06:19:57.042155 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.043s	user 0.029s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":21312,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:19:57.042662 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=2.188937
I20260812 06:19:57.059047 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.016s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5501,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.059757 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushMRSOp(f94ee07bf1694561aea4b8e3cde01156): perf score=1.000000
I20260812 06:19:57.113272 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushMRSOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.053s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":47,"dirs.run_cpu_time_us":246,"dirs.run_wall_time_us":1406,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1475,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:57.114243 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling LogGCOp(f94ee07bf1694561aea4b8e3cde01156): free 112692382 bytes of WAL
I20260812 06:19:57.114490 17384 log_reader.cc:385] T f94ee07bf1694561aea4b8e3cde01156: removed 11 log segments from log reader
I20260812 06:19:57.114540 17384 log.cc:1079] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/f94ee07bf1694561aea4b8e3cde01156/wal-000000003 (ops 12-16)
I20260812 06:19:57.114576 17384 log.cc:1079] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/f94ee07bf1694561aea4b8e3cde01156/wal-000000004 (ops 17-21)
I20260812 06:19:57.114609 17384 log.cc:1079] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/f94ee07bf1694561aea4b8e3cde01156/wal-000000005 (ops 22-26)
I20260812 06:19:57.114638 17384 log.cc:1079] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/f94ee07bf1694561aea4b8e3cde01156/wal-000000006 (ops 27-31)
I20260812 06:19:57.114667 17384 log.cc:1079] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/f94ee07bf1694561aea4b8e3cde01156/wal-000000007 (ops 32-36)
I20260812 06:19:57.114699 17384 log.cc:1079] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/f94ee07bf1694561aea4b8e3cde01156/wal-000000008 (ops 37-41)
I20260812 06:19:57.114728 17384 log.cc:1079] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/f94ee07bf1694561aea4b8e3cde01156/wal-000000009 (ops 42-46)
I20260812 06:19:57.114758 17384 log.cc:1079] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/f94ee07bf1694561aea4b8e3cde01156/wal-000000010 (ops 47-51)
I20260812 06:19:57.114789 17384 log.cc:1079] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/f94ee07bf1694561aea4b8e3cde01156/wal-000000011 (ops 52-56)
I20260812 06:19:57.114817 17384 log.cc:1079] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/f94ee07bf1694561aea4b8e3cde01156/wal-000000012 (ops 57-61)
I20260812 06:19:57.114847 17384 log.cc:1079] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/f94ee07bf1694561aea4b8e3cde01156/wal-000000013 (ops 62-66)
I20260812 06:19:57.134943 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: LogGCOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.021s	user 0.000s	sys 0.017s Metrics: {}
I20260812 06:19:57.135388 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling UndoDeltaBlockGCOp(f94ee07bf1694561aea4b8e3cde01156): 462 bytes on disk
I20260812 06:19:57.135871 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: UndoDeltaBlockGCOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":90,"lbm_reads_lt_1ms":4}
I20260812 06:19:57.136428 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=7.149875
I20260812 06:19:57.157105 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.020s	user 0.015s	sys 0.004s Metrics: {"bytes_written":8615322,"delete_count":0,"lbm_write_time_us":8123,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:19:57.157670 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling LogGCOp(f94ee07bf1694561aea4b8e3cde01156): free 11564875 bytes of WAL
I20260812 06:19:57.157892 17384 log_reader.cc:385] T f94ee07bf1694561aea4b8e3cde01156: removed 1 log segments from log reader
I20260812 06:19:57.157950 17384 log.cc:1079] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/f94ee07bf1694561aea4b8e3cde01156/wal-000000014 (ops 67-70)
I20260812 06:19:57.160485 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: LogGCOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:57.160856 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=2.188937
I20260812 06:19:57.174199 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4801,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:57.174664 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling MajorDeltaCompactionOp(f94ee07bf1694561aea4b8e3cde01156): perf score=1.000000
I20260812 06:19:57.390475 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: MajorDeltaCompactionOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.216s	user 0.131s	sys 0.068s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020737,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2580,"lbm_read_time_us":11702,"lbm_reads_lt_1ms":766,"lbm_write_time_us":32731,"lbm_writes_lt_1ms":743,"mutex_wait_us":61,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2944,"thread_start_us":146,"threads_started":1,"update_count":3500}
I20260812 06:19:57.391085 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=18.063937
I20260812 06:19:57.447711 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.056s	user 0.034s	sys 0.019s Metrics: {"bytes_written":20512320,"delete_count":0,"lbm_write_time_us":20990,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:57.448261 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=2.188937
I20260812 06:19:57.459237 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3767,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.459758 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling MajorDeltaCompactionOp(f94ee07bf1694561aea4b8e3cde01156): perf score=1.000000
I20260812 06:19:57.641978 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: MajorDeltaCompactionOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.182s	user 0.144s	sys 0.038s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918101,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":771,"lbm_read_time_us":14003,"lbm_reads_lt_1ms":672,"lbm_write_time_us":29904,"lbm_writes_lt_1ms":643,"mutex_wait_us":252,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":384,"update_count":3000}
I20260812 06:19:57.642459 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=14.095187
I20260812 06:19:57.699620 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.057s	user 0.024s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19162,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.700222 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=2.188937
I20260812 06:19:57.714313 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5446,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.714857 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling MajorDeltaCompactionOp(f94ee07bf1694561aea4b8e3cde01156): perf score=1.000000
I20260812 06:19:57.892795 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: MajorDeltaCompactionOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.177s	user 0.128s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":218,"lbm_read_time_us":13355,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28221,"lbm_writes_lt_1ms":543,"mutex_wait_us":61,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":2500}
I20260812 06:19:57.893325 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=14.095187
I20260812 06:19:57.945072 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.052s	user 0.023s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18222,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.945639 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=2.188937
I20260812 06:19:57.955716 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3738,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.956127 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling MajorDeltaCompactionOp(f94ee07bf1694561aea4b8e3cde01156): perf score=1.000000
I20260812 06:19:58.129261 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: MajorDeltaCompactionOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.173s	user 0.124s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":679,"lbm_read_time_us":11961,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29185,"lbm_writes_lt_1ms":543,"mutex_wait_us":320,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2500}
I20260812 06:19:58.129781 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=10.126437
I20260812 06:19:58.169883 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.040s	user 0.025s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16014,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:58.170418 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=2.188937
I20260812 06:19:58.200071 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.029s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4988,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.200525 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=2.188937
I20260812 06:19:58.210497 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3740,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.211022 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling MajorDeltaCompactionOp(f94ee07bf1694561aea4b8e3cde01156): perf score=1.000000
I20260812 06:19:58.382745 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: MajorDeltaCompactionOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.172s	user 0.125s	sys 0.036s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815802,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":488,"lbm_read_time_us":10918,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27647,"lbm_writes_lt_1ms":543,"mutex_wait_us":271,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2500}
I20260812 06:19:58.383245 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=14.095187
I20260812 06:19:58.434417 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.051s	user 0.019s	sys 0.025s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20291,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:58.434928 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=2.188937
I20260812 06:19:58.452401 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.017s	user 0.005s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3814,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.452920 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushMRSOp(f94ee07bf1694561aea4b8e3cde01156): perf score=1.000000
I20260812 06:19:58.485692 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushMRSOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.033s	user 0.019s	sys 0.008s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":52,"dirs.run_cpu_time_us":164,"dirs.run_wall_time_us":1231,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1423,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:58.486544 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling LogGCOp(f94ee07bf1694561aea4b8e3cde01156): free 112239316 bytes of WAL
I20260812 06:19:58.486809 17384 log_reader.cc:385] T f94ee07bf1694561aea4b8e3cde01156: removed 11 log segments from log reader
I20260812 06:19:58.486865 17384 log.cc:1079] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/f94ee07bf1694561aea4b8e3cde01156/wal-000000015 (ops 71-75)
I20260812 06:19:58.486904 17384 log.cc:1079] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/f94ee07bf1694561aea4b8e3cde01156/wal-000000016 (ops 76-80)
I20260812 06:19:58.486935 17384 log.cc:1079] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/f94ee07bf1694561aea4b8e3cde01156/wal-000000017 (ops 81-85)
I20260812 06:19:58.486960 17384 log.cc:1079] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/f94ee07bf1694561aea4b8e3cde01156/wal-000000018 (ops 86-90)
I20260812 06:19:58.486991 17384 log.cc:1079] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/f94ee07bf1694561aea4b8e3cde01156/wal-000000019 (ops 91-94)
I20260812 06:19:58.487020 17384 log.cc:1079] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/f94ee07bf1694561aea4b8e3cde01156/wal-000000020 (ops 95-99)
I20260812 06:19:58.487051 17384 log.cc:1079] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/f94ee07bf1694561aea4b8e3cde01156/wal-000000021 (ops 100-104)
I20260812 06:19:58.487082 17384 log.cc:1079] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/f94ee07bf1694561aea4b8e3cde01156/wal-000000022 (ops 105-109)
I20260812 06:19:58.487110 17384 log.cc:1079] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/f94ee07bf1694561aea4b8e3cde01156/wal-000000023 (ops 110-114)
I20260812 06:19:58.487141 17384 log.cc:1079] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/f94ee07bf1694561aea4b8e3cde01156/wal-000000024 (ops 115-119)
I20260812 06:19:58.487171 17384 log.cc:1079] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/f94ee07bf1694561aea4b8e3cde01156/wal-000000025 (ops 120-124)
I20260812 06:19:58.507414 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: LogGCOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.021s	user 0.000s	sys 0.017s Metrics: {}
I20260812 06:19:58.507895 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling UndoDeltaBlockGCOp(f94ee07bf1694561aea4b8e3cde01156): 448 bytes on disk
I20260812 06:19:58.508351 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: UndoDeltaBlockGCOp(f94ee07bf1694561aea4b8e3cde01156) 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:58.509116 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=3.181125
I20260812 06:19:58.533562 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.024s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6425,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:58.534070 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=2.188937
I20260812 06:19:58.543452 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.009s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3232,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:58.544130 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling MajorDeltaCompactionOp(f94ee07bf1694561aea4b8e3cde01156): perf score=1.000000
I20260812 06:19:58.747464 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: MajorDeltaCompactionOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.203s	user 0.125s	sys 0.078s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020734,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":554,"lbm_read_time_us":14246,"lbm_reads_lt_1ms":774,"lbm_write_time_us":33745,"lbm_writes_lt_1ms":743,"mutex_wait_us":281,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":384,"thread_start_us":78,"threads_started":1,"update_count":3500}
I20260812 06:19:58.748072 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=14.095187
I20260812 06:19:58.794389 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.046s	user 0.027s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19315,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:58.794979 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=2.188937
I20260812 06:19:58.810642 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5362,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.811149 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling MajorDeltaCompactionOp(f94ee07bf1694561aea4b8e3cde01156): perf score=1.000000
I20260812 06:19:58.964691 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: MajorDeltaCompactionOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.153s	user 0.079s	sys 0.074s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1633,"lbm_read_time_us":9912,"lbm_reads_lt_1ms":564,"lbm_write_time_us":26275,"lbm_writes_lt_1ms":543,"mutex_wait_us":623,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:19:58.965322 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=14.095187
I20260812 06:19:59.008760 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.043s	user 0.036s	sys 0.006s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18889,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:59.009270 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=2.188937
I20260812 06:19:59.025139 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.016s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6125,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.025627 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling MajorDeltaCompactionOp(f94ee07bf1694561aea4b8e3cde01156): perf score=1.000000
I20260812 06:19:59.191915 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: MajorDeltaCompactionOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.166s	user 0.131s	sys 0.035s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":155,"lbm_read_time_us":10920,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28365,"lbm_writes_lt_1ms":543,"mutex_wait_us":49,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:19:59.192669 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=14.095187
I20260812 06:19:59.246366 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.054s	user 0.019s	sys 0.031s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22186,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:59.246954 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=2.188937
I20260812 06:19:59.262319 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5763,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.262841 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling MajorDeltaCompactionOp(f94ee07bf1694561aea4b8e3cde01156): perf score=1.000000
I20260812 06:19:59.440503 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: MajorDeltaCompactionOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.177s	user 0.102s	sys 0.066s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":818,"lbm_read_time_us":11459,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28242,"lbm_writes_lt_1ms":543,"mutex_wait_us":70,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:59.441190 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=14.095187
I20260812 06:19:59.486901 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.046s	user 0.019s	sys 0.021s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18995,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:59.487439 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=2.188937
I20260812 06:19:59.504621 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.017s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3610,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.505072 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling MajorDeltaCompactionOp(f94ee07bf1694561aea4b8e3cde01156): perf score=1.000000
I20260812 06:19:59.675094 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: MajorDeltaCompactionOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.170s	user 0.111s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":97,"lbm_read_time_us":11645,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27050,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2500}
I20260812 06:19:59.675625 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=14.095187
I20260812 06:19:59.723209 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.047s	user 0.022s	sys 0.021s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20199,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:59.723778 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=2.188937
I20260812 06:19:59.734196 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3781,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.734815 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling MajorDeltaCompactionOp(f94ee07bf1694561aea4b8e3cde01156): perf score=1.000000
I20260812 06:19:59.900522 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: MajorDeltaCompactionOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.166s	user 0.122s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":267,"lbm_read_time_us":10342,"lbm_reads_lt_1ms":572,"lbm_write_time_us":24268,"lbm_writes_lt_1ms":543,"mutex_wait_us":88,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:19:59.901196 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=14.095187
I20260812 06:19:59.945201 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.044s	user 0.034s	sys 0.003s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17094,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:59.945739 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=2.188937
I20260812 06:19:59.955958 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3709,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.956552 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushMRSOp(f94ee07bf1694561aea4b8e3cde01156): perf score=1.000000
I20260812 06:19:59.992584 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushMRSOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.036s	user 0.034s	sys 0.001s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":34,"dirs.run_cpu_time_us":174,"dirs.run_wall_time_us":1303,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2063,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:59.993450 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling LogGCOp(f94ee07bf1694561aea4b8e3cde01156): free 133024628 bytes of WAL
I20260812 06:19:59.993696 17384 log_reader.cc:385] T f94ee07bf1694561aea4b8e3cde01156: removed 13 log segments from log reader
I20260812 06:19:59.993798 17384 log.cc:1079] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/f94ee07bf1694561aea4b8e3cde01156/wal-000000026 (ops 125-129)
I20260812 06:19:59.993870 17384 log.cc:1079] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/f94ee07bf1694561aea4b8e3cde01156/wal-000000027 (ops 130-134)
I20260812 06:19:59.993906 17384 log.cc:1079] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/f94ee07bf1694561aea4b8e3cde01156/wal-000000028 (ops 135-139)
I20260812 06:19:59.993928 17384 log.cc:1079] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/f94ee07bf1694561aea4b8e3cde01156/wal-000000029 (ops 140-144)
I20260812 06:19:59.993985 17384 log.cc:1079] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/f94ee07bf1694561aea4b8e3cde01156/wal-000000030 (ops 145-149)
I20260812 06:19:59.994035 17384 log.cc:1079] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/f94ee07bf1694561aea4b8e3cde01156/wal-000000031 (ops 150-154)
I20260812 06:19:59.994071 17384 log.cc:1079] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/f94ee07bf1694561aea4b8e3cde01156/wal-000000032 (ops 155-159)
I20260812 06:19:59.994122 17384 log.cc:1079] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/f94ee07bf1694561aea4b8e3cde01156/wal-000000033 (ops 160-164)
I20260812 06:19:59.994159 17384 log.cc:1079] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/f94ee07bf1694561aea4b8e3cde01156/wal-000000034 (ops 165-169)
I20260812 06:19:59.994213 17384 log.cc:1079] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/f94ee07bf1694561aea4b8e3cde01156/wal-000000035 (ops 170-174)
I20260812 06:19:59.994246 17384 log.cc:1079] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/f94ee07bf1694561aea4b8e3cde01156/wal-000000036 (ops 175-179)
I20260812 06:19:59.994287 17384 log.cc:1079] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/f94ee07bf1694561aea4b8e3cde01156/wal-000000037 (ops 180-184)
I20260812 06:19:59.994319 17384 log.cc:1079] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/f94ee07bf1694561aea4b8e3cde01156/wal-000000038 (ops 185-188)
I20260812 06:20:00.019028 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: LogGCOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.025s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:20:00.019426 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling UndoDeltaBlockGCOp(f94ee07bf1694561aea4b8e3cde01156): 492 bytes on disk
I20260812 06:20:00.019891 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: UndoDeltaBlockGCOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":90,"lbm_reads_lt_1ms":4}
I20260812 06:20:00.020558 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=3.181125
I20260812 06:20:00.036753 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4553930,"delete_count":0,"lbm_write_time_us":4756,"lbm_writes_lt_1ms":114,"reinsert_count":0,"update_count":555}
I20260812 06:20:00.037235 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=2.188937
I20260812 06:20:00.051301 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.014s	user 0.008s	sys 0.003s Metrics: {"bytes_written":3651380,"delete_count":0,"lbm_write_time_us":5052,"lbm_writes_lt_1ms":92,"reinsert_count":0,"update_count":445}
I20260812 06:20:00.051855 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling MajorDeltaCompactionOp(f94ee07bf1694561aea4b8e3cde01156): perf score=1.000000
I20260812 06:20:00.238804 17185 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.688s	user 1.664s	sys 0.178s
I20260812 06:20:00.261262 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: MajorDeltaCompactionOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.209s	user 0.139s	sys 0.069s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020737,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":15828,"lbm_reads_lt_1ms":770,"lbm_write_time_us":34756,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"update_count":3500}
I20260812 06:20:00.261835 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156): perf score=14.095187
I20260812 06:20:00.314473 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: FlushDeltaMemStoresOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.052s	user 0.020s	sys 0.031s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24009,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:00.315042 17481 maintenance_manager.cc:419] P 901411e8a2e04086b7164ddd90a992f6: Scheduling MajorDeltaCompactionOp(f94ee07bf1694561aea4b8e3cde01156): perf score=1.000000
I20260812 06:20:00.350231 17185 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.111s	user 0.002s	sys 0.000s
I20260812 06:20:00.350816 17185 tablet_server.cc:179] TabletServer@127.16.200.65:0 shutting down...
I20260812 06:20:00.446425 17384 maintenance_manager.cc:643] P 901411e8a2e04086b7164ddd90a992f6: MajorDeltaCompactionOp(f94ee07bf1694561aea4b8e3cde01156) complete. Timing: real 0.131s	user 0.088s	sys 0.038s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713152,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":337,"lbm_read_time_us":9880,"lbm_reads_lt_1ms":467,"lbm_write_time_us":18954,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":2000}
I20260812 06:20:00.447062 17185 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:00.447454 17185 tablet_replica.cc:333] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6: stopping tablet replica
I20260812 06:20:00.447729 17185 raft_consensus.cc:2243] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:00.447956 17185 raft_consensus.cc:2272] T f94ee07bf1694561aea4b8e3cde01156 P 901411e8a2e04086b7164ddd90a992f6 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:00.463497 17185 tablet_server.cc:196] TabletServer@127.16.200.65:0 shutdown complete.
I20260812 06:20:00.485963 17185 master.cc:562] Master@127.16.200.126:36635 shutting down...
I20260812 06:20:00.489755 17185 raft_consensus.cc:2243] T 00000000000000000000000000000000 P d0862ac119764046b89874b6d7a07055 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:00.489941 17185 raft_consensus.cc:2272] T 00000000000000000000000000000000 P d0862ac119764046b89874b6d7a07055 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:00.490016 17185 tablet_replica.cc:333] T 00000000000000000000000000000000 P d0862ac119764046b89874b6d7a07055: stopping tablet replica
I20260812 06:20:00.502151 17185 master.cc:584] Master@127.16.200.126:36635 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5278 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:00.575634 17185 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.16.200.126:39717
I20260812 06:20:00.576061 17185 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:00.578065 17540 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:00.578226 17185 server_base.cc:1061] running on GCE node
W20260812 06:20:00.578110 17533 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:00.578040 17535 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:00.578486 17185 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:00.578528 17185 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:00.578547 17185 hybrid_clock.cc:648] HybridClock initialized: now 1786515600578546 us; error 0 us; skew 500 ppm
I20260812 06:20:00.579334 17185 webserver.cc:533] Webserver started at http://127.16.200.126:35721/ using document root <none> and password file <none>
I20260812 06:20:00.579489 17185 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:00.579540 17185 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:00.579615 17185 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:00.580022 17185 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/master-0-root/instance:
uuid: "815e5d5df5174e149233f52676a10b10"
format_stamp: "Formatted at 2026-08-12 06:20:00 on dist-test-slave-6bbx"
I20260812 06:20:00.581462 17185 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:00.582340 17550 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:00.582549 17185 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:00.582620 17185 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/master-0-root
uuid: "815e5d5df5174e149233f52676a10b10"
format_stamp: "Formatted at 2026-08-12 06:20:00 on dist-test-slave-6bbx"
I20260812 06:20:00.582691 17185 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:00.591053 17185 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:00.591461 17185 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:00.595407 17185 rpc_server.cc:307] RPC server started. Bound to: 127.16.200.126:39717
I20260812 06:20:00.608431 17623 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.16.200.126:39717 every 8 connection(s)
I20260812 06:20:00.608934 17624 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:00.610764 17624 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 815e5d5df5174e149233f52676a10b10: Bootstrap starting.
I20260812 06:20:00.611548 17624 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 815e5d5df5174e149233f52676a10b10: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:00.612598 17624 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 815e5d5df5174e149233f52676a10b10: No bootstrap required, opened a new log
I20260812 06:20:00.613008 17624 raft_consensus.cc:359] T 00000000000000000000000000000000 P 815e5d5df5174e149233f52676a10b10 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "815e5d5df5174e149233f52676a10b10" member_type: VOTER }
I20260812 06:20:00.613096 17624 raft_consensus.cc:385] T 00000000000000000000000000000000 P 815e5d5df5174e149233f52676a10b10 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:00.613127 17624 raft_consensus.cc:740] T 00000000000000000000000000000000 P 815e5d5df5174e149233f52676a10b10 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 815e5d5df5174e149233f52676a10b10, State: Initialized, Role: FOLLOWER
I20260812 06:20:00.613269 17624 consensus_queue.cc:260] T 00000000000000000000000000000000 P 815e5d5df5174e149233f52676a10b10 [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: "815e5d5df5174e149233f52676a10b10" member_type: VOTER }
I20260812 06:20:00.613358 17624 raft_consensus.cc:399] T 00000000000000000000000000000000 P 815e5d5df5174e149233f52676a10b10 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:00.613397 17624 raft_consensus.cc:493] T 00000000000000000000000000000000 P 815e5d5df5174e149233f52676a10b10 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:00.613445 17624 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 815e5d5df5174e149233f52676a10b10 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:00.614133 17624 raft_consensus.cc:515] T 00000000000000000000000000000000 P 815e5d5df5174e149233f52676a10b10 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "815e5d5df5174e149233f52676a10b10" member_type: VOTER }
I20260812 06:20:00.614260 17624 leader_election.cc:304] T 00000000000000000000000000000000 P 815e5d5df5174e149233f52676a10b10 [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: 815e5d5df5174e149233f52676a10b10; no voters: 
I20260812 06:20:00.614449 17624 leader_election.cc:290] T 00000000000000000000000000000000 P 815e5d5df5174e149233f52676a10b10 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:00.614542 17634 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 815e5d5df5174e149233f52676a10b10 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:00.614729 17634 raft_consensus.cc:697] T 00000000000000000000000000000000 P 815e5d5df5174e149233f52676a10b10 [term 1 LEADER]: Becoming Leader. State: Replica: 815e5d5df5174e149233f52676a10b10, State: Running, Role: LEADER
I20260812 06:20:00.614881 17624 sys_catalog.cc:565] T 00000000000000000000000000000000 P 815e5d5df5174e149233f52676a10b10 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:00.614862 17634 consensus_queue.cc:237] T 00000000000000000000000000000000 P 815e5d5df5174e149233f52676a10b10 [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: "815e5d5df5174e149233f52676a10b10" member_type: VOTER }
I20260812 06:20:00.615278 17635 sys_catalog.cc:455] T 00000000000000000000000000000000 P 815e5d5df5174e149233f52676a10b10 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "815e5d5df5174e149233f52676a10b10" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "815e5d5df5174e149233f52676a10b10" member_type: VOTER } }
I20260812 06:20:00.615316 17636 sys_catalog.cc:455] T 00000000000000000000000000000000 P 815e5d5df5174e149233f52676a10b10 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 815e5d5df5174e149233f52676a10b10. Latest consensus state: current_term: 1 leader_uuid: "815e5d5df5174e149233f52676a10b10" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "815e5d5df5174e149233f52676a10b10" member_type: VOTER } }
I20260812 06:20:00.615367 17635 sys_catalog.cc:458] T 00000000000000000000000000000000 P 815e5d5df5174e149233f52676a10b10 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:00.615564 17636 sys_catalog.cc:458] T 00000000000000000000000000000000 P 815e5d5df5174e149233f52676a10b10 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:00.615716 17638 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:00.616631 17638 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:00.616830 17185 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:00.618273 17638 catalog_manager.cc:1383] Generated new cluster ID: fa1f6d7dfafa4741b0cd2511ea6480b4
I20260812 06:20:00.618320 17638 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:00.625825 17638 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:00.626335 17638 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:00.632355 17638 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 815e5d5df5174e149233f52676a10b10: Generated new TSK 0
I20260812 06:20:00.632486 17638 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:00.649075 17185 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:00.651031 17671 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:00.651108 17669 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:00.651216 17185 server_base.cc:1061] running on GCE node
W20260812 06:20:00.651108 17667 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:20:00.651453 17185 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:00.651502 17185 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:00.651517 17185 hybrid_clock.cc:648] HybridClock initialized: now 1786515600651517 us; error 0 us; skew 500 ppm
I20260812 06:20:00.652372 17185 webserver.cc:533] Webserver started at http://127.16.200.65:40021/ using document root <none> and password file <none>
I20260812 06:20:00.652530 17185 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:00.652587 17185 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:00.652660 17185 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:00.653046 17185 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/instance:
uuid: "2551dae055864a7eb31b25c94a433a04"
format_stamp: "Formatted at 2026-08-12 06:20:00 on dist-test-slave-6bbx"
I20260812 06:20:00.654464 17185 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:00.655347 17679 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:00.655576 17185 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:00.655640 17185 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root
uuid: "2551dae055864a7eb31b25c94a433a04"
format_stamp: "Formatted at 2026-08-12 06:20:00 on dist-test-slave-6bbx"
I20260812 06:20:00.655728 17185 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:00.667398 17185 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:00.667806 17185 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:00.668105 17185 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:00.668568 17185 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:00.668606 17185 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:00.668638 17185 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:00.668665 17185 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:00.672540 17185 rpc_server.cc:307] RPC server started. Bound to: 127.16.200.65:33677
I20260812 06:20:00.672585 17784 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.16.200.65:33677 every 8 connection(s)
I20260812 06:20:00.679934 17786 heartbeater.cc:344] Connected to a master server at 127.16.200.126:39717
I20260812 06:20:00.680058 17786 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:00.680292 17786 heartbeater.cc:507] Master 127.16.200.126:39717 requested a full tablet report, sending...
I20260812 06:20:00.680893 17568 ts_manager.cc:194] Registered new tserver with Master: 2551dae055864a7eb31b25c94a433a04 (127.16.200.65:33677)
I20260812 06:20:00.681622 17568 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:55654
I20260812 06:20:00.681702 17185 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008768025s
I20260812 06:20:00.688243 17568 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:55670:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:00.696566 17731 tablet_service.cc:1511] Processing CreateTablet for tablet 747234ee36294176a1cd7bf4056bd792 (DEFAULT_TABLE table=heavy-update-compaction-test [id=369183537a894d39a84c260a39d304c4]), partition=
I20260812 06:20:00.696828 17731 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 747234ee36294176a1cd7bf4056bd792. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:00.698693 17804 tablet_bootstrap.cc:492] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Bootstrap starting.
I20260812 06:20:00.699512 17804 tablet_bootstrap.cc:654] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:00.700578 17804 tablet_bootstrap.cc:492] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: No bootstrap required, opened a new log
I20260812 06:20:00.700657 17804 ts_tablet_manager.cc:1403] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.001s
I20260812 06:20:00.701057 17804 raft_consensus.cc:359] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2551dae055864a7eb31b25c94a433a04" member_type: VOTER last_known_addr { host: "127.16.200.65" port: 33677 } }
I20260812 06:20:00.701146 17804 raft_consensus.cc:385] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:00.701180 17804 raft_consensus.cc:740] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2551dae055864a7eb31b25c94a433a04, State: Initialized, Role: FOLLOWER
I20260812 06:20:00.701318 17804 consensus_queue.cc:260] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04 [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: "2551dae055864a7eb31b25c94a433a04" member_type: VOTER last_known_addr { host: "127.16.200.65" port: 33677 } }
I20260812 06:20:00.701388 17804 raft_consensus.cc:399] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:00.701423 17804 raft_consensus.cc:493] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:00.701471 17804 raft_consensus.cc:3060] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:00.702293 17804 raft_consensus.cc:515] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2551dae055864a7eb31b25c94a433a04" member_type: VOTER last_known_addr { host: "127.16.200.65" port: 33677 } }
I20260812 06:20:00.702419 17804 leader_election.cc:304] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04 [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: 2551dae055864a7eb31b25c94a433a04; no voters: 
I20260812 06:20:00.702580 17804 leader_election.cc:290] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:00.702708 17810 raft_consensus.cc:2804] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:00.702899 17804 ts_tablet_manager.cc:1434] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:20:00.702915 17810 raft_consensus.cc:697] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04 [term 1 LEADER]: Becoming Leader. State: Replica: 2551dae055864a7eb31b25c94a433a04, State: Running, Role: LEADER
I20260812 06:20:00.703017 17786 heartbeater.cc:499] Master 127.16.200.126:39717 was elected leader, sending a full tablet report...
I20260812 06:20:00.703109 17810 consensus_queue.cc:237] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04 [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: "2551dae055864a7eb31b25c94a433a04" member_type: VOTER last_known_addr { host: "127.16.200.65" port: 33677 } }
I20260812 06:20:00.704435 17568 catalog_manager.cc:5719] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04 reported cstate change: term changed from 0 to 1, leader changed from <none> to 2551dae055864a7eb31b25c94a433a04 (127.16.200.65). New cstate: current_term: 1 leader_uuid: "2551dae055864a7eb31b25c94a433a04" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2551dae055864a7eb31b25c94a433a04" member_type: VOTER last_known_addr { host: "127.16.200.65" port: 33677 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:00.760610 17185 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.049s	user 0.022s	sys 0.000s
I20260812 06:20:00.923362 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushMRSOp(747234ee36294176a1cd7bf4056bd792): perf score=23.023690
I20260812 06:20:01.075608 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushMRSOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.152s	user 0.121s	sys 0.027s Metrics: {"bytes_written":12307491,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":51,"dirs.run_cpu_time_us":176,"dirs.run_wall_time_us":844,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40975,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1500}
I20260812 06:20:01.076483 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling LogGCOp(747234ee36294176a1cd7bf4056bd792): free 20743880 bytes of WAL
I20260812 06:20:01.077147 17688 log_reader.cc:385] T 747234ee36294176a1cd7bf4056bd792: removed 2 log segments from log reader
I20260812 06:20:01.077268 17688 log.cc:1079] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/747234ee36294176a1cd7bf4056bd792/wal-000000001 (ops 1-6)
I20260812 06:20:01.077363 17688 log.cc:1079] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/747234ee36294176a1cd7bf4056bd792/wal-000000002 (ops 7-11)
I20260812 06:20:01.082647 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: LogGCOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.006s	user 0.001s	sys 0.004s Metrics: {}
I20260812 06:20:01.083060 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=2.188937
I20260812 06:20:01.114801 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.032s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6449,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.115231 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling UndoDeltaBlockGCOp(747234ee36294176a1cd7bf4056bd792): 20513814 bytes on disk
I20260812 06:20:01.115703 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: UndoDeltaBlockGCOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:20:01.116180 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=2.188937
I20260812 06:20:01.126194 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3948,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.126750 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling MajorDeltaCompactionOp(747234ee36294176a1cd7bf4056bd792): perf score=1.000000
I20260812 06:20:01.302004 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: MajorDeltaCompactionOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.175s	user 0.119s	sys 0.056s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815804,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":775,"lbm_read_time_us":12934,"lbm_reads_lt_1ms":569,"lbm_write_time_us":27495,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6784,"thread_start_us":309,"threads_started":5,"update_count":2500}
I20260812 06:20:01.302598 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=14.095187
I20260812 06:20:01.355252 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.052s	user 0.032s	sys 0.016s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":22770,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:01.355721 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=2.188937
I20260812 06:20:01.373386 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.017s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3723,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.373878 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling MajorDeltaCompactionOp(747234ee36294176a1cd7bf4056bd792): perf score=1.000000
I20260812 06:20:01.556159 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: MajorDeltaCompactionOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.182s	user 0.126s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815681,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":3631,"lbm_read_time_us":11256,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28534,"lbm_writes_lt_1ms":543,"mutex_wait_us":3088,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:20:01.557135 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=14.095187
I20260812 06:20:01.598527 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.041s	user 0.026s	sys 0.012s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":18372,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:01.598991 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=2.188937
I20260812 06:20:01.609751 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3766,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.610231 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling MajorDeltaCompactionOp(747234ee36294176a1cd7bf4056bd792): perf score=1.000000
I20260812 06:20:01.761049 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: MajorDeltaCompactionOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.151s	user 0.114s	sys 0.033s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":927,"lbm_read_time_us":11801,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26888,"lbm_writes_lt_1ms":543,"mutex_wait_us":243,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":27904,"update_count":2500}
I20260812 06:20:01.761533 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=11.118625
I20260812 06:20:01.798024 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.036s	user 0.022s	sys 0.012s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":15254,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:01.798977 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=2.188937
I20260812 06:20:01.822919 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.024s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4604,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:01.823405 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=2.188937
I20260812 06:20:01.838418 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5218,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.838990 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling MajorDeltaCompactionOp(747234ee36294176a1cd7bf4056bd792): perf score=1.000000
I20260812 06:20:01.992128 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: MajorDeltaCompactionOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.153s	user 0.121s	sys 0.024s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815795,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":444,"lbm_read_time_us":11569,"lbm_reads_lt_1ms":573,"lbm_write_time_us":25281,"lbm_writes_lt_1ms":543,"mutex_wait_us":183,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:20:01.993111 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=11.118625
I20260812 06:20:02.031481 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.038s	user 0.024s	sys 0.010s Metrics: {"bytes_written":13456166,"delete_count":0,"lbm_write_time_us":15139,"lbm_writes_lt_1ms":331,"mutex_wait_us":37,"reinsert_count":0,"update_count":1640}
I20260812 06:20:02.032097 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=1.196750
I20260812 06:20:02.051221 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.019s	user 0.006s	sys 0.001s Metrics: {"bytes_written":2953955,"delete_count":0,"lbm_write_time_us":3029,"lbm_writes_lt_1ms":75,"reinsert_count":0,"update_count":360}
I20260812 06:20:02.051720 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=2.188937
I20260812 06:20:02.061378 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3503,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.061802 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling MajorDeltaCompactionOp(747234ee36294176a1cd7bf4056bd792): perf score=1.000000
I20260812 06:20:02.207609 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: MajorDeltaCompactionOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.146s	user 0.109s	sys 0.036s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815774,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":790,"lbm_read_time_us":9640,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28461,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6144,"update_count":2500}
I20260812 06:20:02.211079 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=10.126437
I20260812 06:20:02.244511 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.033s	user 0.016s	sys 0.016s Metrics: {"bytes_written":12676713,"delete_count":0,"lbm_write_time_us":12489,"lbm_writes_lt_1ms":312,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":1545}
I20260812 06:20:02.245046 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=2.188937
I20260812 06:20:02.261356 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.016s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3733434,"delete_count":0,"lbm_write_time_us":4541,"lbm_writes_lt_1ms":94,"reinsert_count":0,"update_count":455}
I20260812 06:20:02.261797 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushMRSOp(747234ee36294176a1cd7bf4056bd792): perf score=1.000000
I20260812 06:20:02.314329 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushMRSOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.052s	user 0.027s	sys 0.005s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":54,"dirs.run_cpu_time_us":230,"dirs.run_wall_time_us":1361,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1493,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:02.314963 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling LogGCOp(747234ee36294176a1cd7bf4056bd792): free 124710297 bytes of WAL
I20260812 06:20:02.315181 17688 log_reader.cc:385] T 747234ee36294176a1cd7bf4056bd792: removed 12 log segments from log reader
I20260812 06:20:02.315225 17688 log.cc:1079] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/747234ee36294176a1cd7bf4056bd792/wal-000000003 (ops 12-16)
I20260812 06:20:02.315254 17688 log.cc:1079] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/747234ee36294176a1cd7bf4056bd792/wal-000000004 (ops 17-21)
I20260812 06:20:02.315292 17688 log.cc:1079] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/747234ee36294176a1cd7bf4056bd792/wal-000000005 (ops 22-26)
I20260812 06:20:02.315325 17688 log.cc:1079] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/747234ee36294176a1cd7bf4056bd792/wal-000000006 (ops 27-31)
I20260812 06:20:02.315356 17688 log.cc:1079] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/747234ee36294176a1cd7bf4056bd792/wal-000000007 (ops 32-36)
I20260812 06:20:02.315387 17688 log.cc:1079] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/747234ee36294176a1cd7bf4056bd792/wal-000000008 (ops 37-41)
I20260812 06:20:02.315418 17688 log.cc:1079] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/747234ee36294176a1cd7bf4056bd792/wal-000000009 (ops 42-46)
I20260812 06:20:02.315510 17688 log.cc:1079] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/747234ee36294176a1cd7bf4056bd792/wal-000000010 (ops 47-51)
I20260812 06:20:02.315548 17688 log.cc:1079] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/747234ee36294176a1cd7bf4056bd792/wal-000000011 (ops 52-56)
I20260812 06:20:02.315570 17688 log.cc:1079] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/747234ee36294176a1cd7bf4056bd792/wal-000000012 (ops 57-61)
I20260812 06:20:02.315603 17688 log.cc:1079] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/747234ee36294176a1cd7bf4056bd792/wal-000000013 (ops 62-66)
I20260812 06:20:02.315641 17688 log.cc:1079] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/747234ee36294176a1cd7bf4056bd792/wal-000000014 (ops 67-71)
I20260812 06:20:02.337775 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: LogGCOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.023s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:20:02.338210 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=7.149875
I20260812 06:20:02.359452 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.021s	user 0.018s	sys 0.000s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":8374,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:20:02.359972 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=2.188937
I20260812 06:20:02.376856 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.017s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5680,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:02.377275 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling UndoDeltaBlockGCOp(747234ee36294176a1cd7bf4056bd792): 471 bytes on disk
I20260812 06:20:02.377662 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: UndoDeltaBlockGCOp(747234ee36294176a1cd7bf4056bd792) 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:20:02.378203 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling MajorDeltaCompactionOp(747234ee36294176a1cd7bf4056bd792): perf score=1.000000
I20260812 06:20:02.567780 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: MajorDeltaCompactionOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.189s	user 0.136s	sys 0.048s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020736,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":527,"lbm_read_time_us":11622,"lbm_reads_lt_1ms":766,"lbm_write_time_us":35378,"lbm_writes_lt_1ms":743,"mutex_wait_us":2,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1792,"thread_start_us":101,"threads_started":1,"update_count":3500}
I20260812 06:20:02.568332 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=15.087375
I20260812 06:20:02.613497 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.045s	user 0.032s	sys 0.011s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":19666,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:20:02.614073 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=2.188937
I20260812 06:20:02.633886 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.020s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4955,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:02.634305 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=2.188937
I20260812 06:20:02.644016 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3579,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.644486 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling MajorDeltaCompactionOp(747234ee36294176a1cd7bf4056bd792): perf score=1.000000
I20260812 06:20:02.800325 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: MajorDeltaCompactionOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.156s	user 0.124s	sys 0.032s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918201,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":921,"lbm_read_time_us":10998,"lbm_reads_lt_1ms":673,"lbm_write_time_us":29593,"lbm_writes_lt_1ms":643,"mutex_wait_us":283,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3000}
I20260812 06:20:02.800979 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=14.095187
I20260812 06:20:02.851493 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.050s	user 0.028s	sys 0.019s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20237,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:02.852144 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=2.188937
I20260812 06:20:02.865110 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.013s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4468,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.865520 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling MajorDeltaCompactionOp(747234ee36294176a1cd7bf4056bd792): perf score=1.000000
I20260812 06:20:03.004825 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: MajorDeltaCompactionOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.139s	user 0.098s	sys 0.041s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":885,"lbm_read_time_us":8605,"lbm_reads_lt_1ms":564,"lbm_write_time_us":25457,"lbm_writes_lt_1ms":543,"mutex_wait_us":269,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:03.005383 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=14.095187
I20260812 06:20:03.061231 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.056s	user 0.019s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18151,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:03.061779 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=2.188937
I20260812 06:20:03.071599 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3486,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.072192 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling MajorDeltaCompactionOp(747234ee36294176a1cd7bf4056bd792): perf score=1.000000
I20260812 06:20:03.242038 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: MajorDeltaCompactionOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.170s	user 0.124s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":217,"lbm_read_time_us":12233,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28123,"lbm_writes_lt_1ms":543,"mutex_wait_us":49,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":46080,"update_count":2500}
I20260812 06:20:03.242659 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=14.095187
I20260812 06:20:03.299490 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.057s	user 0.032s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19508,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:03.300040 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=2.188937
I20260812 06:20:03.316442 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.016s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6005,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.317184 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling MajorDeltaCompactionOp(747234ee36294176a1cd7bf4056bd792): perf score=1.000000
I20260812 06:20:03.477347 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: MajorDeltaCompactionOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.160s	user 0.100s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":242,"lbm_read_time_us":11582,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25334,"lbm_writes_lt_1ms":543,"mutex_wait_us":17,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2500}
I20260812 06:20:03.477972 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=14.095187
I20260812 06:20:03.537494 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.059s	user 0.030s	sys 0.027s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22496,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:03.538231 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=2.188937
I20260812 06:20:03.550356 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4758,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.550808 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushMRSOp(747234ee36294176a1cd7bf4056bd792): perf score=1.000000
I20260812 06:20:03.579902 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushMRSOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.029s	user 0.025s	sys 0.004s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":164,"dirs.run_wall_time_us":1168,"drs_written":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1927,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:03.580511 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling LogGCOp(747234ee36294176a1cd7bf4056bd792): free 120553332 bytes of WAL
I20260812 06:20:03.580750 17688 log_reader.cc:385] T 747234ee36294176a1cd7bf4056bd792: removed 12 log segments from log reader
I20260812 06:20:03.580811 17688 log.cc:1079] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/747234ee36294176a1cd7bf4056bd792/wal-000000015 (ops 72-76)
I20260812 06:20:03.580854 17688 log.cc:1079] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/747234ee36294176a1cd7bf4056bd792/wal-000000016 (ops 77-80)
I20260812 06:20:03.580883 17688 log.cc:1079] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/747234ee36294176a1cd7bf4056bd792/wal-000000017 (ops 81-85)
I20260812 06:20:03.580915 17688 log.cc:1079] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/747234ee36294176a1cd7bf4056bd792/wal-000000018 (ops 86-90)
I20260812 06:20:03.580947 17688 log.cc:1079] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/747234ee36294176a1cd7bf4056bd792/wal-000000019 (ops 91-95)
I20260812 06:20:03.580978 17688 log.cc:1079] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/747234ee36294176a1cd7bf4056bd792/wal-000000020 (ops 96-100)
I20260812 06:20:03.581007 17688 log.cc:1079] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/747234ee36294176a1cd7bf4056bd792/wal-000000021 (ops 101-104)
I20260812 06:20:03.581034 17688 log.cc:1079] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/747234ee36294176a1cd7bf4056bd792/wal-000000022 (ops 105-109)
I20260812 06:20:03.581064 17688 log.cc:1079] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/747234ee36294176a1cd7bf4056bd792/wal-000000023 (ops 110-114)
I20260812 06:20:03.581097 17688 log.cc:1079] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/747234ee36294176a1cd7bf4056bd792/wal-000000024 (ops 115-119)
I20260812 06:20:03.581125 17688 log.cc:1079] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/747234ee36294176a1cd7bf4056bd792/wal-000000025 (ops 120-124)
I20260812 06:20:03.581152 17688 log.cc:1079] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/747234ee36294176a1cd7bf4056bd792/wal-000000026 (ops 125-129)
I20260812 06:20:03.604964 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: LogGCOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.024s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:20:03.605337 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling UndoDeltaBlockGCOp(747234ee36294176a1cd7bf4056bd792): 462 bytes on disk
I20260812 06:20:03.605897 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: UndoDeltaBlockGCOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:20:03.606472 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=4.173312
I20260812 06:20:03.619616 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":5579539,"delete_count":0,"lbm_write_time_us":5207,"lbm_writes_lt_1ms":139,"reinsert_count":0,"update_count":680}
I20260812 06:20:03.620057 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=1.196750
I20260812 06:20:03.627033 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.007s	user 0.002s	sys 0.004s Metrics: {"bytes_written":2625754,"delete_count":0,"lbm_write_time_us":2314,"lbm_writes_lt_1ms":67,"reinsert_count":0,"update_count":320}
I20260812 06:20:03.627717 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling MajorDeltaCompactionOp(747234ee36294176a1cd7bf4056bd792): perf score=1.000000
I20260812 06:20:03.842135 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: MajorDeltaCompactionOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.214s	user 0.144s	sys 0.061s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020712,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":510,"lbm_read_time_us":14083,"lbm_reads_lt_1ms":774,"lbm_write_time_us":34569,"lbm_writes_lt_1ms":743,"mutex_wait_us":2,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":22528,"thread_start_us":71,"threads_started":1,"update_count":3500}
I20260812 06:20:03.842680 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=18.063937
I20260812 06:20:03.897159 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.054s	user 0.030s	sys 0.023s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":24073,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:03.897661 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=2.188937
I20260812 06:20:03.908978 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4136,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.909495 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling MajorDeltaCompactionOp(747234ee36294176a1cd7bf4056bd792): perf score=1.000000
I20260812 06:20:04.075107 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: MajorDeltaCompactionOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.165s	user 0.133s	sys 0.032s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918099,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":374,"lbm_read_time_us":12444,"lbm_reads_lt_1ms":672,"lbm_write_time_us":32919,"lbm_writes_lt_1ms":643,"mutex_wait_us":31,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":20992,"update_count":3000}
I20260812 06:20:04.075712 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=14.095187
I20260812 06:20:04.125440 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.050s	user 0.035s	sys 0.013s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21864,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:04.125929 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=2.188937
I20260812 06:20:04.136207 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3730,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.136843 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling MajorDeltaCompactionOp(747234ee36294176a1cd7bf4056bd792): perf score=1.000000
I20260812 06:20:04.283906 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: MajorDeltaCompactionOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.147s	user 0.105s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":190,"lbm_read_time_us":9206,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27304,"lbm_writes_lt_1ms":543,"mutex_wait_us":30,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17920,"update_count":2500}
I20260812 06:20:04.284606 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=12.110812
I20260812 06:20:04.321410 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.037s	user 0.011s	sys 0.024s Metrics: {"bytes_written":13702315,"delete_count":0,"lbm_write_time_us":15730,"lbm_writes_lt_1ms":337,"reinsert_count":0,"update_count":1670}
I20260812 06:20:04.322088 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=1.196750
I20260812 06:20:04.334923 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.013s	user 0.000s	sys 0.008s Metrics: {"bytes_written":2871909,"delete_count":0,"lbm_write_time_us":3524,"lbm_writes_lt_1ms":73,"reinsert_count":0,"update_count":350}
I20260812 06:20:04.335431 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling MajorDeltaCompactionOp(747234ee36294176a1cd7bf4056bd792): perf score=1.000000
I20260812 06:20:04.488878 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: MajorDeltaCompactionOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.153s	user 0.118s	sys 0.028s Metrics: {"cfile_cache_miss":436,"cfile_cache_miss_bytes":20877347,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":960,"lbm_read_time_us":10103,"lbm_reads_lt_1ms":468,"lbm_write_time_us":22768,"lbm_writes_lt_1ms":447,"mutex_wait_us":262,"peak_mem_usage":50853468,"reinsert_count":0,"update_count":2020}
I20260812 06:20:04.489457 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=14.095187
I20260812 06:20:04.534375 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.045s	user 0.019s	sys 0.016s Metrics: {"bytes_written":16245808,"delete_count":0,"lbm_write_time_us":16008,"lbm_writes_lt_1ms":399,"reinsert_count":0,"update_count":1980}
I20260812 06:20:04.534955 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=2.188937
I20260812 06:20:04.559304 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.024s	user 0.002s	sys 0.019s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5965,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.559938 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling MajorDeltaCompactionOp(747234ee36294176a1cd7bf4056bd792): perf score=1.000000
I20260812 06:20:04.732146 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: MajorDeltaCompactionOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.172s	user 0.113s	sys 0.053s Metrics: {"cfile_cache_miss":528,"cfile_cache_miss_bytes":24651590,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":338,"lbm_read_time_us":10568,"lbm_reads_lt_1ms":568,"lbm_write_time_us":27540,"lbm_writes_lt_1ms":539,"mutex_wait_us":44,"peak_mem_usage":61911376,"reinsert_count":0,"spinlock_wait_cycles":18048,"update_count":2480}
I20260812 06:20:04.732656 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=14.095187
I20260812 06:20:04.778891 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.046s	user 0.038s	sys 0.004s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19911,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:04.779419 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=2.188937
I20260812 06:20:04.789795 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3702,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:04.790355 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling MajorDeltaCompactionOp(747234ee36294176a1cd7bf4056bd792): perf score=1.000000
I20260812 06:20:04.967649 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: MajorDeltaCompactionOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.177s	user 0.107s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":134,"lbm_read_time_us":11332,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30296,"lbm_writes_lt_1ms":543,"mutex_wait_us":52,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12928,"update_count":2500}
I20260812 06:20:04.968339 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=14.095187
I20260812 06:20:05.016427 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.048s	user 0.025s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19624,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:05.016979 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=2.188937
I20260812 06:20:05.027894 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3772,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:05.028358 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushMRSOp(747234ee36294176a1cd7bf4056bd792): perf score=1.000000
I20260812 06:20:05.053911 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushMRSOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.025s	user 0.024s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":207,"dirs.run_wall_time_us":1349,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1426,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:05.054579 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling LogGCOp(747234ee36294176a1cd7bf4056bd792): free 128867742 bytes of WAL
I20260812 06:20:05.054812 17688 log_reader.cc:385] T 747234ee36294176a1cd7bf4056bd792: removed 13 log segments from log reader
I20260812 06:20:05.054857 17688 log.cc:1079] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/747234ee36294176a1cd7bf4056bd792/wal-000000027 (ops 130-134)
I20260812 06:20:05.054886 17688 log.cc:1079] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/747234ee36294176a1cd7bf4056bd792/wal-000000028 (ops 135-138)
I20260812 06:20:05.054917 17688 log.cc:1079] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/747234ee36294176a1cd7bf4056bd792/wal-000000029 (ops 139-143)
I20260812 06:20:05.054950 17688 log.cc:1079] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/747234ee36294176a1cd7bf4056bd792/wal-000000030 (ops 144-148)
I20260812 06:20:05.054981 17688 log.cc:1079] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/747234ee36294176a1cd7bf4056bd792/wal-000000031 (ops 149-153)
I20260812 06:20:05.055013 17688 log.cc:1079] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/747234ee36294176a1cd7bf4056bd792/wal-000000032 (ops 154-158)
I20260812 06:20:05.055044 17688 log.cc:1079] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/747234ee36294176a1cd7bf4056bd792/wal-000000033 (ops 159-162)
I20260812 06:20:05.055075 17688 log.cc:1079] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/747234ee36294176a1cd7bf4056bd792/wal-000000034 (ops 163-167)
I20260812 06:20:05.055106 17688 log.cc:1079] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/747234ee36294176a1cd7bf4056bd792/wal-000000035 (ops 168-172)
I20260812 06:20:05.055135 17688 log.cc:1079] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/747234ee36294176a1cd7bf4056bd792/wal-000000036 (ops 173-176)
I20260812 06:20:05.055164 17688 log.cc:1079] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/747234ee36294176a1cd7bf4056bd792/wal-000000037 (ops 177-181)
I20260812 06:20:05.055194 17688 log.cc:1079] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/747234ee36294176a1cd7bf4056bd792/wal-000000038 (ops 182-186)
I20260812 06:20:05.055225 17688 log.cc:1079] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: Deleting log segment in path: /tmp/dist-test-taskl0_VBK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515595286934-17185-0/minicluster-data/ts-0-root/wals/747234ee36294176a1cd7bf4056bd792/wal-000000039 (ops 187-191)
I20260812 06:20:05.079152 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: LogGCOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.024s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:20:05.080680 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling UndoDeltaBlockGCOp(747234ee36294176a1cd7bf4056bd792): 482 bytes on disk
I20260812 06:20:05.081686 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: UndoDeltaBlockGCOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:20:05.082470 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=3.181125
I20260812 06:20:05.101460 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.019s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4433,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:05.101890 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=2.188937
I20260812 06:20:05.111325 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3588,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:05.111785 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling MajorDeltaCompactionOp(747234ee36294176a1cd7bf4056bd792): perf score=1.000000
I20260812 06:20:05.261354 17185 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.501s	user 1.651s	sys 0.110s
I20260812 06:20:05.323940 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: MajorDeltaCompactionOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.212s	user 0.142s	sys 0.069s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020732,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":637,"lbm_read_time_us":15467,"lbm_reads_lt_1ms":770,"lbm_write_time_us":36072,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"thread_start_us":77,"threads_started":1,"update_count":3500}
I20260812 06:20:05.324503 17787 maintenance_manager.cc:419] P 2551dae055864a7eb31b25c94a433a04: Scheduling FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792): perf score=10.126437
I20260812 06:20:05.339228 17185 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.077s	user 0.001s	sys 0.000s
I20260812 06:20:05.339768 17185 tablet_server.cc:179] TabletServer@127.16.200.65:0 shutting down...
I20260812 06:20:05.360246 17688 maintenance_manager.cc:643] P 2551dae055864a7eb31b25c94a433a04: FlushDeltaMemStoresOp(747234ee36294176a1cd7bf4056bd792) complete. Timing: real 0.036s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":11990,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:05.360818 17185 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:05.361027 17185 tablet_replica.cc:333] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04: stopping tablet replica
I20260812 06:20:05.361160 17185 raft_consensus.cc:2243] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:05.361320 17185 raft_consensus.cc:2272] T 747234ee36294176a1cd7bf4056bd792 P 2551dae055864a7eb31b25c94a433a04 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:05.364408 17185 tablet_server.cc:196] TabletServer@127.16.200.65:0 shutdown complete.
I20260812 06:20:05.383754 17185 master.cc:562] Master@127.16.200.126:39717 shutting down...
I20260812 06:20:05.386569 17185 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 815e5d5df5174e149233f52676a10b10 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:05.386734 17185 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 815e5d5df5174e149233f52676a10b10 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:05.386803 17185 tablet_replica.cc:333] T 00000000000000000000000000000000 P 815e5d5df5174e149233f52676a10b10: stopping tablet replica
I20260812 06:20:05.398746 17185 master.cc:584] Master@127.16.200.126:39717 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (4894 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10173 ms total)

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