[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:18:10.384009 26639 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.26.3.254:33819
I20260812 06:18:10.384872 26639 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:18:10.385445 26639 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:10.391075 26649 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:10.391235 26639 server_base.cc:1061] running on GCE node
W20260812 06:18:10.391084 26654 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:10.391299 26650 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:10.391782 26639 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:10.391871 26639 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:10.391912 26639 hybrid_clock.cc:648] HybridClock initialized: now 1786515490391910 us; error 0 us; skew 500 ppm
I20260812 06:18:10.393414 26639 webserver.cc:533] Webserver started at http://127.26.3.254:35753/ using document root <none> and password file <none>
I20260812 06:18:10.393894 26639 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:10.393954 26639 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:10.394151 26639 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:10.395577 26639 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/master-0-root/instance:
uuid: "bafeef36bead497f9d6d89463cd9b085"
format_stamp: "Formatted at 2026-08-12 06:18:10 on dist-test-slave-2j7r"
I20260812 06:18:10.398691 26639 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:18:10.400447 26663 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:10.401332 26639 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:10.401430 26639 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/master-0-root
uuid: "bafeef36bead497f9d6d89463cd9b085"
format_stamp: "Formatted at 2026-08-12 06:18:10 on dist-test-slave-2j7r"
I20260812 06:18:10.401504 26639 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:10.425053 26639 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:10.425601 26639 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:18:10.425740 26639 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:10.432452 26639 rpc_server.cc:307] RPC server started. Bound to: 127.26.3.254:33819
I20260812 06:18:10.432484 26756 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.3.254:33819 every 8 connection(s)
I20260812 06:18:10.434516 26757 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:10.439483 26757 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P bafeef36bead497f9d6d89463cd9b085: Bootstrap starting.
I20260812 06:18:10.441637 26757 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P bafeef36bead497f9d6d89463cd9b085: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:10.442459 26757 log.cc:826] T 00000000000000000000000000000000 P bafeef36bead497f9d6d89463cd9b085: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:10.443853 26757 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P bafeef36bead497f9d6d89463cd9b085: No bootstrap required, opened a new log
I20260812 06:18:10.446470 26757 raft_consensus.cc:359] T 00000000000000000000000000000000 P bafeef36bead497f9d6d89463cd9b085 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bafeef36bead497f9d6d89463cd9b085" member_type: VOTER }
I20260812 06:18:10.446615 26757 raft_consensus.cc:385] T 00000000000000000000000000000000 P bafeef36bead497f9d6d89463cd9b085 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:10.446678 26757 raft_consensus.cc:740] T 00000000000000000000000000000000 P bafeef36bead497f9d6d89463cd9b085 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: bafeef36bead497f9d6d89463cd9b085, State: Initialized, Role: FOLLOWER
I20260812 06:18:10.447182 26757 consensus_queue.cc:260] T 00000000000000000000000000000000 P bafeef36bead497f9d6d89463cd9b085 [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: "bafeef36bead497f9d6d89463cd9b085" member_type: VOTER }
I20260812 06:18:10.447314 26757 raft_consensus.cc:399] T 00000000000000000000000000000000 P bafeef36bead497f9d6d89463cd9b085 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:10.447376 26757 raft_consensus.cc:493] T 00000000000000000000000000000000 P bafeef36bead497f9d6d89463cd9b085 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:10.447486 26757 raft_consensus.cc:3060] T 00000000000000000000000000000000 P bafeef36bead497f9d6d89463cd9b085 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:10.448146 26757 raft_consensus.cc:515] T 00000000000000000000000000000000 P bafeef36bead497f9d6d89463cd9b085 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bafeef36bead497f9d6d89463cd9b085" member_type: VOTER }
I20260812 06:18:10.448515 26757 leader_election.cc:304] T 00000000000000000000000000000000 P bafeef36bead497f9d6d89463cd9b085 [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: bafeef36bead497f9d6d89463cd9b085; no voters: 
I20260812 06:18:10.448769 26757 leader_election.cc:290] T 00000000000000000000000000000000 P bafeef36bead497f9d6d89463cd9b085 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:10.448859 26761 raft_consensus.cc:2804] T 00000000000000000000000000000000 P bafeef36bead497f9d6d89463cd9b085 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:10.449035 26761 raft_consensus.cc:697] T 00000000000000000000000000000000 P bafeef36bead497f9d6d89463cd9b085 [term 1 LEADER]: Becoming Leader. State: Replica: bafeef36bead497f9d6d89463cd9b085, State: Running, Role: LEADER
I20260812 06:18:10.449445 26761 consensus_queue.cc:237] T 00000000000000000000000000000000 P bafeef36bead497f9d6d89463cd9b085 [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: "bafeef36bead497f9d6d89463cd9b085" member_type: VOTER }
I20260812 06:18:10.449625 26757 sys_catalog.cc:565] T 00000000000000000000000000000000 P bafeef36bead497f9d6d89463cd9b085 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:10.450958 26763 sys_catalog.cc:455] T 00000000000000000000000000000000 P bafeef36bead497f9d6d89463cd9b085 [sys.catalog]: SysCatalogTable state changed. Reason: New leader bafeef36bead497f9d6d89463cd9b085. Latest consensus state: current_term: 1 leader_uuid: "bafeef36bead497f9d6d89463cd9b085" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bafeef36bead497f9d6d89463cd9b085" member_type: VOTER } }
I20260812 06:18:10.451053 26763 sys_catalog.cc:458] T 00000000000000000000000000000000 P bafeef36bead497f9d6d89463cd9b085 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:10.451004 26762 sys_catalog.cc:455] T 00000000000000000000000000000000 P bafeef36bead497f9d6d89463cd9b085 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "bafeef36bead497f9d6d89463cd9b085" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bafeef36bead497f9d6d89463cd9b085" member_type: VOTER } }
I20260812 06:18:10.451118 26762 sys_catalog.cc:458] T 00000000000000000000000000000000 P bafeef36bead497f9d6d89463cd9b085 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:10.451395 26777 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:10.453678 26777 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:10.453893 26639 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:10.458303 26777 catalog_manager.cc:1383] Generated new cluster ID: 33c95ae59ae74c55867a2f272f83fe4f
I20260812 06:18:10.458352 26777 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:10.472674 26777 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:10.473459 26777 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:10.479085 26777 catalog_manager.cc:6092] T 00000000000000000000000000000000 P bafeef36bead497f9d6d89463cd9b085: Generated new TSK 0
I20260812 06:18:10.479604 26777 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:10.486161 26639 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:10.488536 26797 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:10.488607 26805 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:10.488790 26796 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:10.488835 26639 server_base.cc:1061] running on GCE node
I20260812 06:18:10.489030 26639 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:10.489079 26639 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:10.489138 26639 hybrid_clock.cc:648] HybridClock initialized: now 1786515490489137 us; error 0 us; skew 500 ppm
I20260812 06:18:10.490124 26639 webserver.cc:533] Webserver started at http://127.26.3.193:34713/ using document root <none> and password file <none>
I20260812 06:18:10.490293 26639 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:10.490350 26639 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:10.490419 26639 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:10.490854 26639 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root/instance:
uuid: "2418a73b979d4f1195b25800d5a7a382"
format_stamp: "Formatted at 2026-08-12 06:18:10 on dist-test-slave-2j7r"
I20260812 06:18:10.492535 26639 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:10.493605 26812 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:10.493858 26639 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:18:10.493919 26639 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root
uuid: "2418a73b979d4f1195b25800d5a7a382"
format_stamp: "Formatted at 2026-08-12 06:18:10 on dist-test-slave-2j7r"
I20260812 06:18:10.493978 26639 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:10.500029 26639 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:10.500372 26639 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:10.500731 26639 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:10.501531 26639 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:10.501581 26639 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:10.501623 26639 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:10.501652 26639 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:10.507375 26639 rpc_server.cc:307] RPC server started. Bound to: 127.26.3.193:36407
I20260812 06:18:10.507417 26921 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.3.193:36407 every 8 connection(s)
I20260812 06:18:10.518024 26923 heartbeater.cc:344] Connected to a master server at 127.26.3.254:33819
I20260812 06:18:10.518240 26923 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:10.518673 26923 heartbeater.cc:507] Master 127.26.3.254:33819 requested a full tablet report, sending...
I20260812 06:18:10.520051 26691 ts_manager.cc:194] Registered new tserver with Master: 2418a73b979d4f1195b25800d5a7a382 (127.26.3.193:36407)
I20260812 06:18:10.520148 26639 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012241382s
I20260812 06:18:10.521612 26691 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:58576
I20260812 06:18:10.529247 26691 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:58582:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:10.543231 26861 tablet_service.cc:1511] Processing CreateTablet for tablet 398e6bb17ee64e11b26c9c074c51ad04 (DEFAULT_TABLE table=heavy-update-compaction-test [id=363a05ab80cc404aa3b0380a702b1b81]), partition=
I20260812 06:18:10.543633 26861 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 398e6bb17ee64e11b26c9c074c51ad04. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:10.545900 26941 tablet_bootstrap.cc:492] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Bootstrap starting.
I20260812 06:18:10.547029 26941 tablet_bootstrap.cc:654] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:10.548215 26941 tablet_bootstrap.cc:492] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: No bootstrap required, opened a new log
I20260812 06:18:10.548316 26941 ts_tablet_manager.cc:1403] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:10.548784 26941 raft_consensus.cc:359] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2418a73b979d4f1195b25800d5a7a382" member_type: VOTER last_known_addr { host: "127.26.3.193" port: 36407 } }
I20260812 06:18:10.548899 26941 raft_consensus.cc:385] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:10.548939 26941 raft_consensus.cc:740] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2418a73b979d4f1195b25800d5a7a382, State: Initialized, Role: FOLLOWER
I20260812 06:18:10.549064 26941 consensus_queue.cc:260] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382 [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: "2418a73b979d4f1195b25800d5a7a382" member_type: VOTER last_known_addr { host: "127.26.3.193" port: 36407 } }
I20260812 06:18:10.549188 26941 raft_consensus.cc:399] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:10.549234 26941 raft_consensus.cc:493] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:10.549283 26941 raft_consensus.cc:3060] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:10.550211 26941 raft_consensus.cc:515] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2418a73b979d4f1195b25800d5a7a382" member_type: VOTER last_known_addr { host: "127.26.3.193" port: 36407 } }
I20260812 06:18:10.550390 26941 leader_election.cc:304] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382 [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: 2418a73b979d4f1195b25800d5a7a382; no voters: 
I20260812 06:18:10.550597 26941 leader_election.cc:290] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:10.550717 26944 raft_consensus.cc:2804] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:10.550959 26941 ts_tablet_manager.cc:1434] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:10.550938 26944 raft_consensus.cc:697] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382 [term 1 LEADER]: Becoming Leader. State: Replica: 2418a73b979d4f1195b25800d5a7a382, State: Running, Role: LEADER
I20260812 06:18:10.551122 26944 consensus_queue.cc:237] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382 [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: "2418a73b979d4f1195b25800d5a7a382" member_type: VOTER last_known_addr { host: "127.26.3.193" port: 36407 } }
I20260812 06:18:10.551364 26923 heartbeater.cc:499] Master 127.26.3.254:33819 was elected leader, sending a full tablet report...
I20260812 06:18:10.553869 26691 catalog_manager.cc:5719] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382 reported cstate change: term changed from 0 to 1, leader changed from <none> to 2418a73b979d4f1195b25800d5a7a382 (127.26.3.193). New cstate: current_term: 1 leader_uuid: "2418a73b979d4f1195b25800d5a7a382" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2418a73b979d4f1195b25800d5a7a382" member_type: VOTER last_known_addr { host: "127.26.3.193" port: 36407 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:10.616443 26639 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.011s	sys 0.013s
I20260812 06:18:10.758344 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushMRSOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=19.054940
I20260812 06:18:10.912051 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushMRSOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.153s	user 0.120s	sys 0.028s Metrics: {"bytes_written":11897249,"cfile_init":1,"compiler_manager_pool.queue_time_us":211,"delete_count":0,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":184,"dirs.run_wall_time_us":931,"drs_written":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4,"lbm_write_time_us":35764,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"thread_start_us":117,"threads_started":1,"update_count":1450}
I20260812 06:18:10.913036 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling LogGCOp(398e6bb17ee64e11b26c9c074c51ad04): free 20743880 bytes of WAL
I20260812 06:18:10.913319 26818 log_reader.cc:385] T 398e6bb17ee64e11b26c9c074c51ad04: removed 2 log segments from log reader
I20260812 06:18:10.913375 26818 log.cc:1079] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/398e6bb17ee64e11b26c9c074c51ad04/wal-000000001 (ops 1-6)
I20260812 06:18:10.913434 26818 log.cc:1079] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/398e6bb17ee64e11b26c9c074c51ad04/wal-000000002 (ops 7-11)
I20260812 06:18:10.917205 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: LogGCOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.004s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:18:10.917599 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling UndoDeltaBlockGCOp(398e6bb17ee64e11b26c9c074c51ad04): 16821650 bytes on disk
I20260812 06:18:10.918296 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: UndoDeltaBlockGCOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:18:10.918816 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=2.188937
I20260812 06:18:10.951380 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.032s	user 0.012s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5983,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:10.951807 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=2.188937
I20260812 06:18:10.961576 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3873,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:10.961911 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling MajorDeltaCompactionOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=1.000000
I20260812 06:18:11.110991 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: MajorDeltaCompactionOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.149s	user 0.109s	sys 0.040s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24405562,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":625,"lbm_read_time_us":10403,"lbm_reads_lt_1ms":559,"lbm_write_time_us":23488,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"thread_start_us":282,"threads_started":5,"update_count":2450}
I20260812 06:18:11.111461 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=10.126437
I20260812 06:18:11.174546 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.063s	user 0.026s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":35701,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:11.175112 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=2.188937
I20260812 06:18:11.188838 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.014s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5097,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.190773 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling MajorDeltaCompactionOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=1.000000
I20260812 06:18:11.326685 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: MajorDeltaCompactionOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.132s	user 0.089s	sys 0.042s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":807,"lbm_read_time_us":9408,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24160,"lbm_writes_lt_1ms":443,"mutex_wait_us":259,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6912,"update_count":2000}
I20260812 06:18:11.327176 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=10.126437
I20260812 06:18:11.374446 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.047s	user 0.012s	sys 0.025s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16176,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:11.374928 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=2.188937
I20260812 06:18:11.389535 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.014s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5448,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.390054 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling MajorDeltaCompactionOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=1.000000
I20260812 06:18:11.526455 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: MajorDeltaCompactionOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.136s	user 0.093s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":142,"lbm_read_time_us":9589,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25849,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2000}
I20260812 06:18:11.526960 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=10.126437
I20260812 06:18:11.571460 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.044s	user 0.016s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17033,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:11.572027 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=2.188937
I20260812 06:18:11.585427 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.013s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5276,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.585810 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling MajorDeltaCompactionOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=1.000000
I20260812 06:18:11.709982 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: MajorDeltaCompactionOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.124s	user 0.104s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":963,"lbm_read_time_us":9674,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23903,"lbm_writes_lt_1ms":443,"mutex_wait_us":332,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16768,"update_count":2000}
I20260812 06:18:11.710671 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=10.126437
I20260812 06:18:11.759809 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.049s	user 0.023s	sys 0.021s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19075,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:11.760361 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=2.188937
I20260812 06:18:11.771214 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4132,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.771660 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling MajorDeltaCompactionOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=1.000000
I20260812 06:18:11.912766 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: MajorDeltaCompactionOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.141s	user 0.113s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":613,"lbm_read_time_us":11777,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24157,"lbm_writes_lt_1ms":443,"mutex_wait_us":41,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:11.913265 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=10.126437
I20260812 06:18:11.946702 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.033s	user 0.023s	sys 0.008s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":14785,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:11.947141 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=2.188937
I20260812 06:18:11.957267 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3968,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.957635 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling MajorDeltaCompactionOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=1.000000
I20260812 06:18:12.078528 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: MajorDeltaCompactionOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.121s	user 0.104s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713275,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1169,"lbm_read_time_us":9492,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23604,"lbm_writes_lt_1ms":443,"mutex_wait_us":376,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:12.079010 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=10.126437
I20260812 06:18:12.119036 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.040s	user 0.014s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14362,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:12.119464 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=2.188937
I20260812 06:18:12.129634 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3932,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.130188 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushMRSOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=1.000000
I20260812 06:18:12.155925 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushMRSOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.025s	user 0.023s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":43,"dirs.run_cpu_time_us":182,"dirs.run_wall_time_us":1121,"drs_written":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1379,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:12.156714 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling LogGCOp(398e6bb17ee64e11b26c9c074c51ad04): free 115943174 bytes of WAL
I20260812 06:18:12.156926 26818 log_reader.cc:385] T 398e6bb17ee64e11b26c9c074c51ad04: removed 11 log segments from log reader
I20260812 06:18:12.156972 26818 log.cc:1079] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/398e6bb17ee64e11b26c9c074c51ad04/wal-000000003 (ops 12-16)
I20260812 06:18:12.156999 26818 log.cc:1079] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/398e6bb17ee64e11b26c9c074c51ad04/wal-000000004 (ops 17-21)
I20260812 06:18:12.157027 26818 log.cc:1079] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/398e6bb17ee64e11b26c9c074c51ad04/wal-000000005 (ops 22-26)
I20260812 06:18:12.157058 26818 log.cc:1079] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/398e6bb17ee64e11b26c9c074c51ad04/wal-000000006 (ops 27-31)
I20260812 06:18:12.157104 26818 log.cc:1079] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/398e6bb17ee64e11b26c9c074c51ad04/wal-000000007 (ops 32-36)
I20260812 06:18:12.157140 26818 log.cc:1079] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/398e6bb17ee64e11b26c9c074c51ad04/wal-000000008 (ops 37-41)
I20260812 06:18:12.157172 26818 log.cc:1079] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/398e6bb17ee64e11b26c9c074c51ad04/wal-000000009 (ops 42-46)
I20260812 06:18:12.157203 26818 log.cc:1079] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/398e6bb17ee64e11b26c9c074c51ad04/wal-000000010 (ops 47-51)
I20260812 06:18:12.157233 26818 log.cc:1079] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/398e6bb17ee64e11b26c9c074c51ad04/wal-000000011 (ops 52-56)
I20260812 06:18:12.157265 26818 log.cc:1079] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/398e6bb17ee64e11b26c9c074c51ad04/wal-000000012 (ops 57-61)
I20260812 06:18:12.157295 26818 log.cc:1079] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/398e6bb17ee64e11b26c9c074c51ad04/wal-000000013 (ops 62-66)
I20260812 06:18:12.177649 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: LogGCOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.021s	user 0.002s	sys 0.018s Metrics: {}
I20260812 06:18:12.178073 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling UndoDeltaBlockGCOp(398e6bb17ee64e11b26c9c074c51ad04): 447 bytes on disk
I20260812 06:18:12.178488 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: UndoDeltaBlockGCOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:18:12.179006 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=3.181125
I20260812 06:18:12.192371 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.013s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":3909,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:12.192790 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=2.188937
I20260812 06:18:12.202412 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3329,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:12.202878 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling MajorDeltaCompactionOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=1.000000
I20260812 06:18:12.370675 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: MajorDeltaCompactionOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.168s	user 0.119s	sys 0.039s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918323,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1136,"lbm_read_time_us":13544,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31242,"lbm_writes_lt_1ms":643,"mutex_wait_us":530,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":74,"threads_started":1,"update_count":3000}
I20260812 06:18:12.371606 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=14.095187
I20260812 06:18:12.422206 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.050s	user 0.030s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20908,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:12.422683 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=2.188937
I20260812 06:18:12.432953 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3750,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.433490 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling MajorDeltaCompactionOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=1.000000
I20260812 06:18:12.580395 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: MajorDeltaCompactionOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.147s	user 0.112s	sys 0.025s 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":682,"lbm_read_time_us":9871,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28095,"lbm_writes_lt_1ms":543,"mutex_wait_us":238,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:12.580915 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=14.095187
I20260812 06:18:12.632808 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.052s	user 0.024s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":17556,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:12.633411 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=2.188937
I20260812 06:18:12.645254 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4102,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.645903 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling MajorDeltaCompactionOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=1.000000
I20260812 06:18:12.811157 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: MajorDeltaCompactionOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.165s	user 0.093s	sys 0.072s 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":127,"lbm_read_time_us":12998,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28712,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17664,"update_count":2500}
I20260812 06:18:12.811702 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=14.095187
I20260812 06:18:12.862376 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.051s	user 0.027s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19278,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:12.862929 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=2.188937
I20260812 06:18:12.874465 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4367,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.874938 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling MajorDeltaCompactionOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=1.000000
I20260812 06:18:13.045425 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: MajorDeltaCompactionOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.170s	user 0.122s	sys 0.043s 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":204,"lbm_read_time_us":11872,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30925,"lbm_writes_lt_1ms":543,"mutex_wait_us":73,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:18:13.045864 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=14.095187
I20260812 06:18:13.094990 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.049s	user 0.025s	sys 0.016s Metrics: {"bytes_written":16409881,"delete_count":0,"lbm_write_time_us":19271,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:13.095546 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=2.188937
I20260812 06:18:13.107975 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4582,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.108472 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling MajorDeltaCompactionOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=1.000000
I20260812 06:18:13.288615 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: MajorDeltaCompactionOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.180s	user 0.116s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815663,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":190,"lbm_read_time_us":13754,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34865,"lbm_writes_lt_1ms":543,"mutex_wait_us":17,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":2500}
I20260812 06:18:13.289076 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=15.087375
I20260812 06:18:13.355376 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.066s	user 0.033s	sys 0.021s Metrics: {"bytes_written":16656044,"delete_count":0,"lbm_write_time_us":24159,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":408,"reinsert_count":0,"update_count":2030}
I20260812 06:18:13.355825 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=6.157687
I20260812 06:18:13.374541 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.019s	user 0.013s	sys 0.004s Metrics: {"bytes_written":7958937,"delete_count":0,"lbm_write_time_us":7832,"lbm_writes_lt_1ms":197,"reinsert_count":0,"update_count":970}
I20260812 06:18:13.375078 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushMRSOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=1.000000
I20260812 06:18:13.405803 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushMRSOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.031s	user 0.024s	sys 0.001s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":221,"dirs.run_wall_time_us":1117,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1224,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:13.406476 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling LogGCOp(398e6bb17ee64e11b26c9c074c51ad04): free 121006388 bytes of WAL
I20260812 06:18:13.406673 26818 log_reader.cc:385] T 398e6bb17ee64e11b26c9c074c51ad04: removed 12 log segments from log reader
I20260812 06:18:13.406718 26818 log.cc:1079] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/398e6bb17ee64e11b26c9c074c51ad04/wal-000000014 (ops 67-71)
I20260812 06:18:13.406746 26818 log.cc:1079] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/398e6bb17ee64e11b26c9c074c51ad04/wal-000000015 (ops 72-76)
I20260812 06:18:13.406777 26818 log.cc:1079] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/398e6bb17ee64e11b26c9c074c51ad04/wal-000000016 (ops 77-81)
I20260812 06:18:13.406808 26818 log.cc:1079] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/398e6bb17ee64e11b26c9c074c51ad04/wal-000000017 (ops 82-86)
I20260812 06:18:13.406839 26818 log.cc:1079] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/398e6bb17ee64e11b26c9c074c51ad04/wal-000000018 (ops 87-90)
I20260812 06:18:13.406870 26818 log.cc:1079] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/398e6bb17ee64e11b26c9c074c51ad04/wal-000000019 (ops 91-95)
I20260812 06:18:13.406909 26818 log.cc:1079] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/398e6bb17ee64e11b26c9c074c51ad04/wal-000000020 (ops 96-100)
I20260812 06:18:13.406931 26818 log.cc:1079] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/398e6bb17ee64e11b26c9c074c51ad04/wal-000000021 (ops 101-105)
I20260812 06:18:13.406961 26818 log.cc:1079] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/398e6bb17ee64e11b26c9c074c51ad04/wal-000000022 (ops 106-110)
I20260812 06:18:13.406992 26818 log.cc:1079] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/398e6bb17ee64e11b26c9c074c51ad04/wal-000000023 (ops 111-115)
I20260812 06:18:13.407022 26818 log.cc:1079] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/398e6bb17ee64e11b26c9c074c51ad04/wal-000000024 (ops 116-120)
I20260812 06:18:13.407053 26818 log.cc:1079] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/398e6bb17ee64e11b26c9c074c51ad04/wal-000000025 (ops 121-125)
I20260812 06:18:13.428866 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: LogGCOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.022s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:18:13.429242 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=3.181125
I20260812 06:18:13.453606 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.024s	user 0.012s	sys 0.001s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":5314,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:13.454068 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling UndoDeltaBlockGCOp(398e6bb17ee64e11b26c9c074c51ad04): 447 bytes on disk
I20260812 06:18:13.454530 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: UndoDeltaBlockGCOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4}
I20260812 06:18:13.455063 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=2.188937
I20260812 06:18:13.469481 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.014s	user 0.006s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4904,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:13.470144 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling MajorDeltaCompactionOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=1.000000
I20260812 06:18:13.703677 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: MajorDeltaCompactionOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.233s	user 0.178s	sys 0.049s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37123150,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":250,"lbm_read_time_us":18096,"lbm_reads_lt_1ms":874,"lbm_write_time_us":43680,"lbm_writes_lt_1ms":843,"mutex_wait_us":18,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":7936,"thread_start_us":74,"threads_started":1,"update_count":4000}
I20260812 06:18:13.704216 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=18.063937
I20260812 06:18:13.758236 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.054s	user 0.045s	sys 0.007s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":24447,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:13.758709 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=2.188937
I20260812 06:18:13.770323 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4093,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.770785 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling MajorDeltaCompactionOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=1.000000
I20260812 06:18:13.923157 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: MajorDeltaCompactionOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.152s	user 0.098s	sys 0.054s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918100,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1004,"lbm_read_time_us":10304,"lbm_reads_lt_1ms":664,"lbm_write_time_us":31954,"lbm_writes_lt_1ms":643,"mutex_wait_us":324,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":3000}
I20260812 06:18:13.923672 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=14.095187
I20260812 06:18:13.970383 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.047s	user 0.034s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21023,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:13.970844 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=2.188937
I20260812 06:18:13.980333 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3656,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.980847 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling MajorDeltaCompactionOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=1.000000
I20260812 06:18:14.139806 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: MajorDeltaCompactionOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.159s	user 0.128s	sys 0.018s 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":220,"lbm_read_time_us":12109,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28507,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:18:14.140357 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=14.095187
I20260812 06:18:14.193614 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.053s	user 0.035s	sys 0.008s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19959,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:14.194168 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=2.188937
I20260812 06:18:14.203886 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3548,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.204311 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling MajorDeltaCompactionOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=1.000000
I20260812 06:18:14.367447 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: MajorDeltaCompactionOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.162s	user 0.115s	sys 0.046s 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":1123,"lbm_read_time_us":12043,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30089,"lbm_writes_lt_1ms":543,"mutex_wait_us":1,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:18:14.367921 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=14.095187
I20260812 06:18:14.420346 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.052s	user 0.035s	sys 0.013s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":27518,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:18:14.421149 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=2.188937
I20260812 06:18:14.435674 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5717,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.436110 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling MajorDeltaCompactionOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=1.000000
I20260812 06:18:14.592550 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: MajorDeltaCompactionOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.156s	user 0.104s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":749,"lbm_read_time_us":10617,"lbm_reads_lt_1ms":568,"lbm_write_time_us":30044,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:14.593415 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=14.095187
I20260812 06:18:14.655332 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.062s	user 0.026s	sys 0.031s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":25523,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:14.655941 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=4.173312
I20260812 06:18:14.673240 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.017s	user 0.013s	sys 0.004s Metrics: {"bytes_written":5907729,"delete_count":0,"lbm_write_time_us":7176,"lbm_writes_lt_1ms":147,"reinsert_count":0,"update_count":720}
I20260812 06:18:14.673893 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=1.196750
I20260812 06:18:14.681458 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.007s	user 0.003s	sys 0.004s Metrics: {"bytes_written":2297554,"delete_count":0,"lbm_write_time_us":2488,"lbm_writes_lt_1ms":59,"reinsert_count":0,"update_count":280}
I20260812 06:18:14.681996 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushMRSOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=1.000000
I20260812 06:18:14.714586 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushMRSOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.032s	user 0.028s	sys 0.003s Metrics: {"bytes_written":1193505,"cfile_init":1,"dirs.queue_time_us":39,"dirs.run_cpu_time_us":223,"dirs.run_wall_time_us":1272,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1993,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:14.715430 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling LogGCOp(398e6bb17ee64e11b26c9c074c51ad04): free 120100619 bytes of WAL
I20260812 06:18:14.715652 26818 log_reader.cc:385] T 398e6bb17ee64e11b26c9c074c51ad04: removed 12 log segments from log reader
I20260812 06:18:14.715700 26818 log.cc:1079] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/398e6bb17ee64e11b26c9c074c51ad04/wal-000000026 (ops 126-130)
I20260812 06:18:14.715737 26818 log.cc:1079] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/398e6bb17ee64e11b26c9c074c51ad04/wal-000000027 (ops 131-134)
I20260812 06:18:14.715780 26818 log.cc:1079] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/398e6bb17ee64e11b26c9c074c51ad04/wal-000000028 (ops 135-139)
I20260812 06:18:14.715809 26818 log.cc:1079] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/398e6bb17ee64e11b26c9c074c51ad04/wal-000000029 (ops 140-144)
I20260812 06:18:14.715839 26818 log.cc:1079] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/398e6bb17ee64e11b26c9c074c51ad04/wal-000000030 (ops 145-148)
I20260812 06:18:14.715870 26818 log.cc:1079] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/398e6bb17ee64e11b26c9c074c51ad04/wal-000000031 (ops 149-153)
I20260812 06:18:14.715901 26818 log.cc:1079] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/398e6bb17ee64e11b26c9c074c51ad04/wal-000000032 (ops 154-158)
I20260812 06:18:14.715932 26818 log.cc:1079] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/398e6bb17ee64e11b26c9c074c51ad04/wal-000000033 (ops 159-163)
I20260812 06:18:14.715962 26818 log.cc:1079] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/398e6bb17ee64e11b26c9c074c51ad04/wal-000000034 (ops 164-168)
I20260812 06:18:14.715991 26818 log.cc:1079] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/398e6bb17ee64e11b26c9c074c51ad04/wal-000000035 (ops 169-173)
I20260812 06:18:14.716022 26818 log.cc:1079] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/398e6bb17ee64e11b26c9c074c51ad04/wal-000000036 (ops 174-178)
I20260812 06:18:14.716051 26818 log.cc:1079] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/398e6bb17ee64e11b26c9c074c51ad04/wal-000000037 (ops 179-182)
I20260812 06:18:14.737702 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: LogGCOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.022s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:18:14.738088 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling UndoDeltaBlockGCOp(398e6bb17ee64e11b26c9c074c51ad04): 463 bytes on disk
I20260812 06:18:14.738569 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: UndoDeltaBlockGCOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:18:14.739105 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=3.181125
I20260812 06:18:14.753939 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.015s	user 0.008s	sys 0.002s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4098,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:14.754295 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=2.188937
I20260812 06:18:14.763000 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.009s	user 0.002s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3290,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:14.763368 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling MajorDeltaCompactionOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=1.000000
I20260812 06:18:14.989126 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: MajorDeltaCompactionOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.226s	user 0.153s	sys 0.072s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37123227,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":651,"lbm_read_time_us":17687,"lbm_reads_lt_1ms":875,"lbm_write_time_us":43734,"lbm_writes_lt_1ms":843,"mutex_wait_us":63,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":23680,"thread_start_us":68,"threads_started":1,"update_count":4000}
I20260812 06:18:14.989667 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=18.063937
I20260812 06:18:15.041966 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.052s	user 0.040s	sys 0.011s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":23430,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:15.042482 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=2.188937
I20260812 06:18:15.055660 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: FlushDeltaMemStoresOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.013s	user 0.010s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4597,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.056913 26924 maintenance_manager.cc:419] P 2418a73b979d4f1195b25800d5a7a382: Scheduling MajorDeltaCompactionOp(398e6bb17ee64e11b26c9c074c51ad04): perf score=1.000000
I20260812 06:18:15.147451 26639 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.531s	user 1.601s	sys 0.120s
I20260812 06:18:15.226212 26639 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.078s	user 0.004s	sys 0.000s
I20260812 06:18:15.226938 26639 tablet_server.cc:179] TabletServer@127.26.3.193:0 shutting down...
I20260812 06:18:15.236131 26818 maintenance_manager.cc:643] P 2418a73b979d4f1195b25800d5a7a382: MajorDeltaCompactionOp(398e6bb17ee64e11b26c9c074c51ad04) complete. Timing: real 0.179s	user 0.154s	sys 0.025s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918100,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":205,"lbm_read_time_us":12552,"lbm_reads_lt_1ms":660,"lbm_write_time_us":37311,"lbm_writes_lt_1ms":643,"mutex_wait_us":53,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":3000}
I20260812 06:18:15.238955 26639 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:15.241765 26639 tablet_replica.cc:333] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382: stopping tablet replica
I20260812 06:18:15.241989 26639 raft_consensus.cc:2243] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:15.242190 26639 raft_consensus.cc:2272] T 398e6bb17ee64e11b26c9c074c51ad04 P 2418a73b979d4f1195b25800d5a7a382 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:15.392738 26639 tablet_server.cc:196] TabletServer@127.26.3.193:0 shutdown complete.
I20260812 06:18:15.397377 26639 master.cc:562] Master@127.26.3.254:33819 shutting down...
I20260812 06:18:15.400732 26639 raft_consensus.cc:2243] T 00000000000000000000000000000000 P bafeef36bead497f9d6d89463cd9b085 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:15.400890 26639 raft_consensus.cc:2272] T 00000000000000000000000000000000 P bafeef36bead497f9d6d89463cd9b085 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:15.400960 26639 tablet_replica.cc:333] T 00000000000000000000000000000000 P bafeef36bead497f9d6d89463cd9b085: stopping tablet replica
I20260812 06:18:15.412928 26639 master.cc:584] Master@127.26.3.254:33819 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5103 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:15.487247 26639 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.26.3.254:39797
I20260812 06:18:15.487717 26639 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:15.489468 26977 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:15.489547 26980 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:15.489674 26978 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:15.489768 26639 server_base.cc:1061] running on GCE node
I20260812 06:18:15.489908 26639 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:15.489943 26639 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:15.489964 26639 hybrid_clock.cc:648] HybridClock initialized: now 1786515495489964 us; error 0 us; skew 500 ppm
I20260812 06:18:15.490734 26639 webserver.cc:533] Webserver started at http://127.26.3.254:39421/ using document root <none> and password file <none>
I20260812 06:18:15.490883 26639 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:15.490926 26639 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:15.490998 26639 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:15.491365 26639 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/master-0-root/instance:
uuid: "aeda3421b52d4be790b96938983e50e5"
format_stamp: "Formatted at 2026-08-12 06:18:15 on dist-test-slave-2j7r"
I20260812 06:18:15.492707 26639 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:15.493631 26992 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:15.493844 26639 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:18:15.493909 26639 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/master-0-root
uuid: "aeda3421b52d4be790b96938983e50e5"
format_stamp: "Formatted at 2026-08-12 06:18:15 on dist-test-slave-2j7r"
I20260812 06:18:15.493974 26639 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:15.509933 26639 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:15.510238 26639 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:15.514739 26639 rpc_server.cc:307] RPC server started. Bound to: 127.26.3.254:39797
I20260812 06:18:15.523809 27091 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:15.531155 27089 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.3.254:39797 every 8 connection(s)
I20260812 06:18:15.532344 27091 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P aeda3421b52d4be790b96938983e50e5: Bootstrap starting.
I20260812 06:18:15.533133 27091 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P aeda3421b52d4be790b96938983e50e5: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:15.534086 27091 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P aeda3421b52d4be790b96938983e50e5: No bootstrap required, opened a new log
I20260812 06:18:15.534466 27091 raft_consensus.cc:359] T 00000000000000000000000000000000 P aeda3421b52d4be790b96938983e50e5 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "aeda3421b52d4be790b96938983e50e5" member_type: VOTER }
I20260812 06:18:15.534548 27091 raft_consensus.cc:385] T 00000000000000000000000000000000 P aeda3421b52d4be790b96938983e50e5 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:15.534577 27091 raft_consensus.cc:740] T 00000000000000000000000000000000 P aeda3421b52d4be790b96938983e50e5 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: aeda3421b52d4be790b96938983e50e5, State: Initialized, Role: FOLLOWER
I20260812 06:18:15.534718 27091 consensus_queue.cc:260] T 00000000000000000000000000000000 P aeda3421b52d4be790b96938983e50e5 [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: "aeda3421b52d4be790b96938983e50e5" member_type: VOTER }
I20260812 06:18:15.534802 27091 raft_consensus.cc:399] T 00000000000000000000000000000000 P aeda3421b52d4be790b96938983e50e5 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:15.534842 27091 raft_consensus.cc:493] T 00000000000000000000000000000000 P aeda3421b52d4be790b96938983e50e5 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:15.534890 27091 raft_consensus.cc:3060] T 00000000000000000000000000000000 P aeda3421b52d4be790b96938983e50e5 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:15.535517 27091 raft_consensus.cc:515] T 00000000000000000000000000000000 P aeda3421b52d4be790b96938983e50e5 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "aeda3421b52d4be790b96938983e50e5" member_type: VOTER }
I20260812 06:18:15.535642 27091 leader_election.cc:304] T 00000000000000000000000000000000 P aeda3421b52d4be790b96938983e50e5 [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: aeda3421b52d4be790b96938983e50e5; no voters: 
I20260812 06:18:15.535807 27091 leader_election.cc:290] T 00000000000000000000000000000000 P aeda3421b52d4be790b96938983e50e5 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:15.535943 27095 raft_consensus.cc:2804] T 00000000000000000000000000000000 P aeda3421b52d4be790b96938983e50e5 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:15.536137 27095 raft_consensus.cc:697] T 00000000000000000000000000000000 P aeda3421b52d4be790b96938983e50e5 [term 1 LEADER]: Becoming Leader. State: Replica: aeda3421b52d4be790b96938983e50e5, State: Running, Role: LEADER
I20260812 06:18:15.536239 27091 sys_catalog.cc:565] T 00000000000000000000000000000000 P aeda3421b52d4be790b96938983e50e5 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:15.536289 27095 consensus_queue.cc:237] T 00000000000000000000000000000000 P aeda3421b52d4be790b96938983e50e5 [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: "aeda3421b52d4be790b96938983e50e5" member_type: VOTER }
I20260812 06:18:15.536726 27096 sys_catalog.cc:455] T 00000000000000000000000000000000 P aeda3421b52d4be790b96938983e50e5 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "aeda3421b52d4be790b96938983e50e5" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "aeda3421b52d4be790b96938983e50e5" member_type: VOTER } }
I20260812 06:18:15.536757 27098 sys_catalog.cc:455] T 00000000000000000000000000000000 P aeda3421b52d4be790b96938983e50e5 [sys.catalog]: SysCatalogTable state changed. Reason: New leader aeda3421b52d4be790b96938983e50e5. Latest consensus state: current_term: 1 leader_uuid: "aeda3421b52d4be790b96938983e50e5" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "aeda3421b52d4be790b96938983e50e5" member_type: VOTER } }
I20260812 06:18:15.536827 27096 sys_catalog.cc:458] T 00000000000000000000000000000000 P aeda3421b52d4be790b96938983e50e5 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:15.536849 27098 sys_catalog.cc:458] T 00000000000000000000000000000000 P aeda3421b52d4be790b96938983e50e5 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:15.537076 27104 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:15.538003 27104 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:15.538209 26639 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:15.539834 27104 catalog_manager.cc:1383] Generated new cluster ID: 988c07ad7bcb472289723f573a58aae0
I20260812 06:18:15.539896 27104 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:15.559042 27104 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:15.559583 27104 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:15.577052 27104 catalog_manager.cc:6092] T 00000000000000000000000000000000 P aeda3421b52d4be790b96938983e50e5: Generated new TSK 0
I20260812 06:18:15.577267 27104 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:15.602633 26639 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:15.604498 27124 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:15.604534 27123 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:15.604636 26639 server_base.cc:1061] running on GCE node
W20260812 06:18:15.604734 27135 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:15.604914 26639 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:15.604962 26639 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:15.604976 26639 hybrid_clock.cc:648] HybridClock initialized: now 1786515495604977 us; error 0 us; skew 500 ppm
I20260812 06:18:15.605798 26639 webserver.cc:533] Webserver started at http://127.26.3.193:33639/ using document root <none> and password file <none>
I20260812 06:18:15.605964 26639 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:15.606015 26639 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:15.606091 26639 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:15.606473 26639 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/instance:
uuid: "2f559a39090946579933cdd77a4fb007"
format_stamp: "Formatted at 2026-08-12 06:18:15 on dist-test-slave-2j7r"
I20260812 06:18:15.607932 26639 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:15.608810 27142 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:15.609045 26639 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:15.609148 26639 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root
uuid: "2f559a39090946579933cdd77a4fb007"
format_stamp: "Formatted at 2026-08-12 06:18:15 on dist-test-slave-2j7r"
I20260812 06:18:15.609229 26639 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:15.615453 26639 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:15.615756 26639 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:15.616004 26639 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:15.616420 26639 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:15.616456 26639 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:15.616496 26639 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:15.616523 26639 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:15.620462 26639 rpc_server.cc:307] RPC server started. Bound to: 127.26.3.193:35085
I20260812 06:18:15.620502 27266 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.3.193:35085 every 8 connection(s)
I20260812 06:18:15.627693 27267 heartbeater.cc:344] Connected to a master server at 127.26.3.254:39797
I20260812 06:18:15.627789 27267 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:15.627997 27267 heartbeater.cc:507] Master 127.26.3.254:39797 requested a full tablet report, sending...
I20260812 06:18:15.628618 27024 ts_manager.cc:194] Registered new tserver with Master: 2f559a39090946579933cdd77a4fb007 (127.26.3.193:35085)
I20260812 06:18:15.629355 27024 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:40050
I20260812 06:18:15.629626 26639 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008764748s
I20260812 06:18:15.635800 27024 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:40058:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:15.643702 27203 tablet_service.cc:1511] Processing CreateTablet for tablet a5f3e9f72e534fc18de82af7e8f06cde (DEFAULT_TABLE table=heavy-update-compaction-test [id=2aa4ad9ac52b4831be976d457a7fd317]), partition=
I20260812 06:18:15.643921 27203 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet a5f3e9f72e534fc18de82af7e8f06cde. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:15.645789 27291 tablet_bootstrap.cc:492] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Bootstrap starting.
I20260812 06:18:15.646675 27291 tablet_bootstrap.cc:654] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:15.647581 27291 tablet_bootstrap.cc:492] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: No bootstrap required, opened a new log
I20260812 06:18:15.647653 27291 ts_tablet_manager.cc:1403] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:18:15.647987 27291 raft_consensus.cc:359] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2f559a39090946579933cdd77a4fb007" member_type: VOTER last_known_addr { host: "127.26.3.193" port: 35085 } }
I20260812 06:18:15.648066 27291 raft_consensus.cc:385] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:15.648087 27291 raft_consensus.cc:740] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2f559a39090946579933cdd77a4fb007, State: Initialized, Role: FOLLOWER
I20260812 06:18:15.648180 27291 consensus_queue.cc:260] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007 [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: "2f559a39090946579933cdd77a4fb007" member_type: VOTER last_known_addr { host: "127.26.3.193" port: 35085 } }
I20260812 06:18:15.648247 27291 raft_consensus.cc:399] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:15.648269 27291 raft_consensus.cc:493] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:15.648301 27291 raft_consensus.cc:3060] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:15.648994 27291 raft_consensus.cc:515] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2f559a39090946579933cdd77a4fb007" member_type: VOTER last_known_addr { host: "127.26.3.193" port: 35085 } }
I20260812 06:18:15.649134 27291 leader_election.cc:304] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007 [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: 2f559a39090946579933cdd77a4fb007; no voters: 
I20260812 06:18:15.649325 27291 leader_election.cc:290] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:15.649452 27294 raft_consensus.cc:2804] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:15.649617 27291 ts_tablet_manager.cc:1434] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:15.649678 27294 raft_consensus.cc:697] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007 [term 1 LEADER]: Becoming Leader. State: Replica: 2f559a39090946579933cdd77a4fb007, State: Running, Role: LEADER
I20260812 06:18:15.649787 27267 heartbeater.cc:499] Master 127.26.3.254:39797 was elected leader, sending a full tablet report...
I20260812 06:18:15.649879 27294 consensus_queue.cc:237] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007 [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: "2f559a39090946579933cdd77a4fb007" member_type: VOTER last_known_addr { host: "127.26.3.193" port: 35085 } }
I20260812 06:18:15.651090 27024 catalog_manager.cc:5719] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007 reported cstate change: term changed from 0 to 1, leader changed from <none> to 2f559a39090946579933cdd77a4fb007 (127.26.3.193). New cstate: current_term: 1 leader_uuid: "2f559a39090946579933cdd77a4fb007" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2f559a39090946579933cdd77a4fb007" member_type: VOTER last_known_addr { host: "127.26.3.193" port: 35085 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:15.703423 26639 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.049s	user 0.005s	sys 0.016s
I20260812 06:18:15.871388 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushMRSOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=23.023690
I20260812 06:18:16.006901 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushMRSOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.135s	user 0.102s	sys 0.031s Metrics: {"bytes_written":12307489,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":200,"dirs.run_wall_time_us":811,"drs_written":1,"lbm_read_time_us":35,"lbm_reads_lt_1ms":4,"lbm_write_time_us":35326,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":896,"update_count":1500}
I20260812 06:18:16.007584 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling LogGCOp(a5f3e9f72e534fc18de82af7e8f06cde): free 20743831 bytes of WAL
I20260812 06:18:16.007793 27157 log_reader.cc:385] T a5f3e9f72e534fc18de82af7e8f06cde: removed 2 log segments from log reader
I20260812 06:18:16.007838 27157 log.cc:1079] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/a5f3e9f72e534fc18de82af7e8f06cde/wal-000000001 (ops 1-6)
I20260812 06:18:16.007869 27157 log.cc:1079] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/a5f3e9f72e534fc18de82af7e8f06cde/wal-000000002 (ops 7-11)
I20260812 06:18:16.011322 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: LogGCOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.004s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:18:16.011612 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=2.188937
I20260812 06:18:16.028860 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.017s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4506,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.029275 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling UndoDeltaBlockGCOp(a5f3e9f72e534fc18de82af7e8f06cde): 20513811 bytes on disk
I20260812 06:18:16.029620 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: UndoDeltaBlockGCOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4}
I20260812 06:18:16.030071 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling MajorDeltaCompactionOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=1.000000
I20260812 06:18:16.153431 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: MajorDeltaCompactionOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.123s	user 0.072s	sys 0.050s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":725,"lbm_read_time_us":8139,"lbm_reads_lt_1ms":460,"lbm_write_time_us":20466,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":324,"threads_started":5,"update_count":2000}
I20260812 06:18:16.154049 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=11.118625
I20260812 06:18:16.190846 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.037s	user 0.019s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15873,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:18:16.191339 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=2.188937
I20260812 06:18:16.215585 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.024s	user 0.004s	sys 0.007s Metrics: {"bytes_written":3774459,"delete_count":0,"lbm_write_time_us":5068,"lbm_writes_lt_1ms":95,"reinsert_count":0,"update_count":460}
I20260812 06:18:16.216185 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=2.188937
I20260812 06:18:16.229821 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.013s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4020609,"delete_count":0,"lbm_write_time_us":5002,"lbm_writes_lt_1ms":101,"reinsert_count":0,"update_count":490}
I20260812 06:18:16.230321 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling MajorDeltaCompactionOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=1.000000
I20260812 06:18:16.377961 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: MajorDeltaCompactionOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.147s	user 0.097s	sys 0.046s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815798,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":233,"lbm_read_time_us":8566,"lbm_reads_lt_1ms":573,"lbm_write_time_us":26479,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2500}
I20260812 06:18:16.378623 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=12.110812
I20260812 06:18:16.423956 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.045s	user 0.021s	sys 0.021s Metrics: {"bytes_written":13579241,"delete_count":0,"lbm_write_time_us":21580,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":331,"reinsert_count":0,"update_count":1655}
I20260812 06:18:16.424413 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=2.188937
I20260812 06:18:16.444517 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.020s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3241134,"delete_count":0,"lbm_write_time_us":3488,"lbm_writes_lt_1ms":82,"reinsert_count":0,"update_count":395}
I20260812 06:18:16.444939 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=2.188937
I20260812 06:18:16.453567 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.008s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3130,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:16.453931 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling MajorDeltaCompactionOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=1.000000
I20260812 06:18:16.622181 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: MajorDeltaCompactionOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.168s	user 0.112s	sys 0.055s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815775,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":113,"lbm_read_time_us":10384,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31316,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9856,"update_count":2500}
I20260812 06:18:16.622864 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=14.095187
I20260812 06:18:16.677240 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.054s	user 0.033s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20969,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:16.677757 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=2.188937
I20260812 06:18:16.692653 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5465,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.693173 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling MajorDeltaCompactionOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=1.000000
I20260812 06:18:16.858687 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: MajorDeltaCompactionOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.165s	user 0.108s	sys 0.057s 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":948,"lbm_read_time_us":14365,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27837,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":2500}
I20260812 06:18:16.859179 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=14.095187
I20260812 06:18:16.915421 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.056s	user 0.024s	sys 0.030s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21244,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:16.916023 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=2.188937
I20260812 06:18:16.930613 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.014s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5530,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.931043 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling MajorDeltaCompactionOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=1.000000
I20260812 06:18:17.107151 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: MajorDeltaCompactionOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.176s	user 0.116s	sys 0.055s 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":290,"lbm_read_time_us":12268,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31013,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:18:17.107676 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=14.095187
I20260812 06:18:17.171702 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.064s	user 0.029s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21765,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:17.172223 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=2.188937
I20260812 06:18:17.182978 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4105,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.183557 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushMRSOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=1.000000
I20260812 06:18:17.213924 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushMRSOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.030s	user 0.021s	sys 0.005s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":198,"dirs.run_wall_time_us":1082,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1396,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:17.214586 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling MajorDeltaCompactionOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=1.000000
I20260812 06:18:17.400198 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: MajorDeltaCompactionOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.185s	user 0.127s	sys 0.058s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":216,"lbm_read_time_us":13274,"lbm_reads_lt_1ms":564,"lbm_write_time_us":33133,"lbm_writes_lt_1ms":543,"mutex_wait_us":61,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2500}
I20260812 06:18:17.400852 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling LogGCOp(a5f3e9f72e534fc18de82af7e8f06cde): free 124257299 bytes of WAL
I20260812 06:18:17.401139 27157 log_reader.cc:385] T a5f3e9f72e534fc18de82af7e8f06cde: removed 12 log segments from log reader
I20260812 06:18:17.401249 27157 log.cc:1079] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/a5f3e9f72e534fc18de82af7e8f06cde/wal-000000003 (ops 12-16)
I20260812 06:18:17.401345 27157 log.cc:1079] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/a5f3e9f72e534fc18de82af7e8f06cde/wal-000000004 (ops 17-21)
I20260812 06:18:17.401396 27157 log.cc:1079] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/a5f3e9f72e534fc18de82af7e8f06cde/wal-000000005 (ops 22-26)
I20260812 06:18:17.401428 27157 log.cc:1079] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/a5f3e9f72e534fc18de82af7e8f06cde/wal-000000006 (ops 27-31)
I20260812 06:18:17.401503 27157 log.cc:1079] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/a5f3e9f72e534fc18de82af7e8f06cde/wal-000000007 (ops 32-36)
I20260812 06:18:17.401548 27157 log.cc:1079] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/a5f3e9f72e534fc18de82af7e8f06cde/wal-000000008 (ops 37-41)
I20260812 06:18:17.401587 27157 log.cc:1079] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/a5f3e9f72e534fc18de82af7e8f06cde/wal-000000009 (ops 42-46)
I20260812 06:18:17.401623 27157 log.cc:1079] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/a5f3e9f72e534fc18de82af7e8f06cde/wal-000000010 (ops 47-50)
I20260812 06:18:17.401657 27157 log.cc:1079] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/a5f3e9f72e534fc18de82af7e8f06cde/wal-000000011 (ops 51-55)
I20260812 06:18:17.401850 27157 log.cc:1079] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/a5f3e9f72e534fc18de82af7e8f06cde/wal-000000012 (ops 56-60)
I20260812 06:18:17.401919 27157 log.cc:1079] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/a5f3e9f72e534fc18de82af7e8f06cde/wal-000000013 (ops 61-65)
I20260812 06:18:17.401960 27157 log.cc:1079] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/a5f3e9f72e534fc18de82af7e8f06cde/wal-000000014 (ops 66-70)
I20260812 06:18:17.426358 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: LogGCOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.025s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:18:17.426803 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=18.063937
I20260812 06:18:17.486624 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.060s	user 0.022s	sys 0.035s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":23592,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:17.487121 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=2.188937
I20260812 06:18:17.496925 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3805,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.497409 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling UndoDeltaBlockGCOp(a5f3e9f72e534fc18de82af7e8f06cde): 462 bytes on disk
I20260812 06:18:17.497821 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: UndoDeltaBlockGCOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:18:17.498337 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling MajorDeltaCompactionOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=1.000000
I20260812 06:18:17.691773 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: MajorDeltaCompactionOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.193s	user 0.133s	sys 0.060s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918097,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":709,"lbm_read_time_us":14644,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33208,"lbm_writes_lt_1ms":643,"mutex_wait_us":280,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":3000}
I20260812 06:18:17.692442 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=14.095187
I20260812 06:18:17.743064 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.050s	user 0.026s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17999,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:17.743589 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=2.188937
I20260812 06:18:17.753530 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3871,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.753906 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling MajorDeltaCompactionOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=1.000000
I20260812 06:18:17.935142 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: MajorDeltaCompactionOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.181s	user 0.115s	sys 0.058s 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":605,"lbm_read_time_us":13989,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28537,"lbm_writes_lt_1ms":543,"mutex_wait_us":327,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18048,"update_count":2500}
I20260812 06:18:17.935652 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=14.095187
I20260812 06:18:17.985378 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.050s	user 0.023s	sys 0.025s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18080,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:17.985988 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=2.188937
I20260812 06:18:17.996881 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3975,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.997380 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling MajorDeltaCompactionOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=1.000000
I20260812 06:18:18.164683 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: MajorDeltaCompactionOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.167s	user 0.103s	sys 0.057s 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":546,"lbm_read_time_us":12087,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27241,"lbm_writes_lt_1ms":543,"mutex_wait_us":334,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2500}
I20260812 06:18:18.165222 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=14.095187
I20260812 06:18:18.209455 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.044s	user 0.024s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17692,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:18.210017 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=2.188937
I20260812 06:18:18.234421 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.024s	user 0.019s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5942,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.235001 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling MajorDeltaCompactionOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=1.000000
I20260812 06:18:18.397023 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: MajorDeltaCompactionOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.162s	user 0.117s	sys 0.045s 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":296,"lbm_read_time_us":12230,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26842,"lbm_writes_lt_1ms":543,"mutex_wait_us":32,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":2500}
I20260812 06:18:18.397557 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=14.095187
I20260812 06:18:18.443707 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.046s	user 0.028s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20762,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:18.444255 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=2.188937
I20260812 06:18:18.455967 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.012s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3920,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.456440 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling MajorDeltaCompactionOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=1.000000
I20260812 06:18:18.622038 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: MajorDeltaCompactionOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.165s	user 0.098s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1028,"lbm_read_time_us":8666,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30832,"lbm_writes_lt_1ms":543,"mutex_wait_us":277,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2500}
I20260812 06:18:18.622550 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=14.095187
I20260812 06:18:18.679462 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.057s	user 0.018s	sys 0.036s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25704,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:18.680039 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=2.188937
I20260812 06:18:18.705667 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.025s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6069,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.706182 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=2.188937
I20260812 06:18:18.716010 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3771,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.716598 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushMRSOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=1.000000
I20260812 06:18:18.753686 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushMRSOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.037s	user 0.036s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":44,"dirs.run_cpu_time_us":251,"dirs.run_wall_time_us":1645,"drs_written":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2050,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:18.754354 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling LogGCOp(a5f3e9f72e534fc18de82af7e8f06cde): free 133477394 bytes of WAL
I20260812 06:18:18.754583 27157 log_reader.cc:385] T a5f3e9f72e534fc18de82af7e8f06cde: removed 13 log segments from log reader
I20260812 06:18:18.754642 27157 log.cc:1079] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/a5f3e9f72e534fc18de82af7e8f06cde/wal-000000015 (ops 71-75)
I20260812 06:18:18.754684 27157 log.cc:1079] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/a5f3e9f72e534fc18de82af7e8f06cde/wal-000000016 (ops 76-80)
I20260812 06:18:18.754719 27157 log.cc:1079] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/a5f3e9f72e534fc18de82af7e8f06cde/wal-000000017 (ops 81-85)
I20260812 06:18:18.754740 27157 log.cc:1079] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/a5f3e9f72e534fc18de82af7e8f06cde/wal-000000018 (ops 86-90)
I20260812 06:18:18.754768 27157 log.cc:1079] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/a5f3e9f72e534fc18de82af7e8f06cde/wal-000000019 (ops 91-95)
I20260812 06:18:18.754793 27157 log.cc:1079] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/a5f3e9f72e534fc18de82af7e8f06cde/wal-000000020 (ops 96-100)
I20260812 06:18:18.754823 27157 log.cc:1079] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/a5f3e9f72e534fc18de82af7e8f06cde/wal-000000021 (ops 101-105)
I20260812 06:18:18.754854 27157 log.cc:1079] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/a5f3e9f72e534fc18de82af7e8f06cde/wal-000000022 (ops 106-110)
I20260812 06:18:18.754884 27157 log.cc:1079] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/a5f3e9f72e534fc18de82af7e8f06cde/wal-000000023 (ops 111-115)
I20260812 06:18:18.754911 27157 log.cc:1079] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/a5f3e9f72e534fc18de82af7e8f06cde/wal-000000024 (ops 116-120)
I20260812 06:18:18.754935 27157 log.cc:1079] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/a5f3e9f72e534fc18de82af7e8f06cde/wal-000000025 (ops 121-125)
I20260812 06:18:18.754963 27157 log.cc:1079] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/a5f3e9f72e534fc18de82af7e8f06cde/wal-000000026 (ops 126-130)
I20260812 06:18:18.754995 27157 log.cc:1079] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/a5f3e9f72e534fc18de82af7e8f06cde/wal-000000027 (ops 131-135)
I20260812 06:18:18.784659 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: LogGCOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.030s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:18:18.785050 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling UndoDeltaBlockGCOp(a5f3e9f72e534fc18de82af7e8f06cde): 492 bytes on disk
I20260812 06:18:18.785501 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: UndoDeltaBlockGCOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:18:18.786094 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=3.181125
I20260812 06:18:18.801697 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.015s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":3896,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:18.802090 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=2.188937
I20260812 06:18:18.814848 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.013s	user 0.002s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4775,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:18.815376 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling MajorDeltaCompactionOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=1.000000
I20260812 06:18:19.059448 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: MajorDeltaCompactionOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.244s	user 0.132s	sys 0.110s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37123266,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":2099,"lbm_read_time_us":17425,"lbm_reads_lt_1ms":875,"lbm_write_time_us":41362,"lbm_writes_lt_1ms":843,"mutex_wait_us":991,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":4608,"thread_start_us":73,"threads_started":1,"update_count":4000}
I20260812 06:18:19.060341 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=18.063937
I20260812 06:18:19.120234 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.060s	user 0.028s	sys 0.020s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":23243,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:19.120678 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=2.188937
I20260812 06:18:19.132025 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4172,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.132436 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling MajorDeltaCompactionOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=1.000000
I20260812 06:18:19.327875 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: MajorDeltaCompactionOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.195s	user 0.127s	sys 0.064s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918096,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":963,"lbm_read_time_us":11048,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33107,"lbm_writes_lt_1ms":643,"mutex_wait_us":573,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7680,"update_count":3000}
I20260812 06:18:19.328378 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=15.087375
I20260812 06:18:19.372943 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.044s	user 0.026s	sys 0.013s Metrics: {"bytes_written":17558580,"delete_count":0,"lbm_write_time_us":18666,"lbm_writes_lt_1ms":431,"mutex_wait_us":529,"reinsert_count":0,"update_count":2140}
I20260812 06:18:19.373505 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=2.188937
I20260812 06:18:19.392895 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.019s	user 0.014s	sys 0.000s Metrics: {"bytes_written":3364209,"delete_count":0,"lbm_write_time_us":5052,"lbm_writes_lt_1ms":85,"reinsert_count":0,"update_count":410}
I20260812 06:18:19.393298 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=2.188937
I20260812 06:18:19.401800 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.008s	user 0.002s	sys 0.006s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3316,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:19.402158 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling MajorDeltaCompactionOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=1.000000
I20260812 06:18:19.588574 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: MajorDeltaCompactionOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.186s	user 0.115s	sys 0.070s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918189,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1202,"lbm_read_time_us":14272,"lbm_reads_lt_1ms":673,"lbm_write_time_us":30530,"lbm_writes_lt_1ms":643,"mutex_wait_us":250,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3000}
I20260812 06:18:19.593418 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=14.095187
I20260812 06:18:19.637557 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.044s	user 0.027s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19149,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:19.638118 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=2.188937
I20260812 06:18:19.655875 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.018s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5304,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.656478 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling MajorDeltaCompactionOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=1.000000
I20260812 06:18:19.829159 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: MajorDeltaCompactionOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.173s	user 0.111s	sys 0.058s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":570,"lbm_read_time_us":10273,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32801,"lbm_writes_lt_1ms":543,"mutex_wait_us":34,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":2500}
I20260812 06:18:19.829679 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=15.087375
I20260812 06:18:19.878180 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.048s	user 0.026s	sys 0.021s Metrics: {"bytes_written":16820144,"delete_count":0,"lbm_write_time_us":21675,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:18:19.878717 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=2.188937
I20260812 06:18:19.893563 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.015s	user 0.010s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4365,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:19.894034 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling MajorDeltaCompactionOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=1.000000
I20260812 06:18:20.057337 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: MajorDeltaCompactionOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.163s	user 0.115s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815672,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":542,"lbm_read_time_us":10789,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28855,"lbm_writes_lt_1ms":543,"mutex_wait_us":287,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:20.058094 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=14.095187
I20260812 06:18:20.112452 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.054s	user 0.040s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21438,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:20.112982 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=2.188937
I20260812 06:18:20.125561 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.012s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4651,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.126322 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushMRSOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=1.000000
I20260812 06:18:20.153901 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushMRSOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.027s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":164,"dirs.run_wall_time_us":1121,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1400,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:20.154609 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling LogGCOp(a5f3e9f72e534fc18de82af7e8f06cde): free 120553644 bytes of WAL
I20260812 06:18:20.154840 27157 log_reader.cc:385] T a5f3e9f72e534fc18de82af7e8f06cde: removed 12 log segments from log reader
I20260812 06:18:20.154897 27157 log.cc:1079] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/a5f3e9f72e534fc18de82af7e8f06cde/wal-000000028 (ops 136-140)
I20260812 06:18:20.154927 27157 log.cc:1079] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/a5f3e9f72e534fc18de82af7e8f06cde/wal-000000029 (ops 141-144)
I20260812 06:18:20.154954 27157 log.cc:1079] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/a5f3e9f72e534fc18de82af7e8f06cde/wal-000000030 (ops 145-149)
I20260812 06:18:20.154986 27157 log.cc:1079] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/a5f3e9f72e534fc18de82af7e8f06cde/wal-000000031 (ops 150-154)
I20260812 06:18:20.155016 27157 log.cc:1079] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/a5f3e9f72e534fc18de82af7e8f06cde/wal-000000032 (ops 155-159)
I20260812 06:18:20.155047 27157 log.cc:1079] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/a5f3e9f72e534fc18de82af7e8f06cde/wal-000000033 (ops 160-164)
I20260812 06:18:20.155078 27157 log.cc:1079] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/a5f3e9f72e534fc18de82af7e8f06cde/wal-000000034 (ops 165-169)
I20260812 06:18:20.155112 27157 log.cc:1079] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/a5f3e9f72e534fc18de82af7e8f06cde/wal-000000035 (ops 170-174)
I20260812 06:18:20.155135 27157 log.cc:1079] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/a5f3e9f72e534fc18de82af7e8f06cde/wal-000000036 (ops 175-179)
I20260812 06:18:20.155165 27157 log.cc:1079] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/a5f3e9f72e534fc18de82af7e8f06cde/wal-000000037 (ops 180-184)
I20260812 06:18:20.155196 27157 log.cc:1079] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/a5f3e9f72e534fc18de82af7e8f06cde/wal-000000038 (ops 185-188)
I20260812 06:18:20.155227 27157 log.cc:1079] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: Deleting log segment in path: /tmp/dist-test-task28NMeA/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515490374166-26639-0/minicluster-data/ts-0-root/wals/a5f3e9f72e534fc18de82af7e8f06cde/wal-000000039 (ops 189-193)
I20260812 06:18:20.175979 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: LogGCOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.021s	user 0.000s	sys 0.018s Metrics: {}
I20260812 06:18:20.176403 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling UndoDeltaBlockGCOp(a5f3e9f72e534fc18de82af7e8f06cde): 473 bytes on disk
I20260812 06:18:20.176932 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: UndoDeltaBlockGCOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4}
I20260812 06:18:20.177479 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=2.188937
I20260812 06:18:20.195299 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.018s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4393,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.195647 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=2.188937
I20260812 06:18:20.205152 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.009s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3782,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.205577 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling MajorDeltaCompactionOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=1.000000
I20260812 06:18:20.333712 26639 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.630s	user 1.617s	sys 0.234s
I20260812 06:18:20.408016 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: MajorDeltaCompactionOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.202s	user 0.130s	sys 0.072s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020745,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":873,"lbm_read_time_us":14827,"lbm_reads_lt_1ms":770,"lbm_write_time_us":32990,"lbm_writes_lt_1ms":743,"mutex_wait_us":598,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":47488,"thread_start_us":84,"threads_started":1,"update_count":3500}
I20260812 06:18:20.409695 27270 maintenance_manager.cc:419] P 2f559a39090946579933cdd77a4fb007: Scheduling FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde): perf score=10.126437
I20260812 06:18:20.417773 26639 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.084s	user 0.003s	sys 0.000s
I20260812 06:18:20.418301 26639 tablet_server.cc:179] TabletServer@127.26.3.193:0 shutting down...
I20260812 06:18:20.440248 27157 maintenance_manager.cc:643] P 2f559a39090946579933cdd77a4fb007: FlushDeltaMemStoresOp(a5f3e9f72e534fc18de82af7e8f06cde) complete. Timing: real 0.030s	user 0.018s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13387,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:20.440724 26639 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:20.440940 26639 tablet_replica.cc:333] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007: stopping tablet replica
I20260812 06:18:20.441067 26639 raft_consensus.cc:2243] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:20.441236 26639 raft_consensus.cc:2272] T a5f3e9f72e534fc18de82af7e8f06cde P 2f559a39090946579933cdd77a4fb007 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:20.444001 26639 tablet_server.cc:196] TabletServer@127.26.3.193:0 shutdown complete.
I20260812 06:18:20.463776 26639 master.cc:562] Master@127.26.3.254:39797 shutting down...
I20260812 06:18:20.467149 26639 raft_consensus.cc:2243] T 00000000000000000000000000000000 P aeda3421b52d4be790b96938983e50e5 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:20.467301 26639 raft_consensus.cc:2272] T 00000000000000000000000000000000 P aeda3421b52d4be790b96938983e50e5 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:20.467372 26639 tablet_replica.cc:333] T 00000000000000000000000000000000 P aeda3421b52d4be790b96938983e50e5: stopping tablet replica
I20260812 06:18:20.479244 26639 master.cc:584] Master@127.26.3.254:39797 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5063 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10167 ms total)

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