[==========] 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:17:13.593643 27730 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.27.20.190:42953
I20260812 06:17:13.594779 27730 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:17:13.595634 27730 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:13.602810 27736 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:17:13.602905 27738 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:17:13.603001 27730 server_base.cc:1061] running on GCE node
W20260812 06:17:13.603224 27735 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:17:13.603706 27730 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:13.603837 27730 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:17:13.603921 27730 hybrid_clock.cc:648] HybridClock initialized: now 1786515433603917 us; error 0 us; skew 500 ppm
I20260812 06:17:13.605708 27730 webserver.cc:533] Webserver started at http://127.27.20.190:37561/ using document root <none> and password file <none>
I20260812 06:17:13.606268 27730 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:13.606359 27730 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:13.606612 27730 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:13.608332 27730 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/master-0-root/instance:
uuid: "be434427641c4420b636978fba6c3f1a"
format_stamp: "Formatted at 2026-08-12 06:17:13 on dist-test-slave-zkpd"
I20260812 06:17:13.611686 27730 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:17:13.613795 27743 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:17:13.614732 27730 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:13.614876 27730 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/master-0-root
uuid: "be434427641c4420b636978fba6c3f1a"
format_stamp: "Formatted at 2026-08-12 06:17:13 on dist-test-slave-zkpd"
I20260812 06:17:13.614982 27730 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-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:17:13.623483 27730 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:13.624128 27730 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:17:13.624301 27730 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:13.631718 27730 rpc_server.cc:307] RPC server started. Bound to: 127.27.20.190:42953
I20260812 06:17:13.631723 27801 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.20.190:42953 every 8 connection(s)
I20260812 06:17:13.633992 27802 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:17:13.639338 27802 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P be434427641c4420b636978fba6c3f1a: Bootstrap starting.
I20260812 06:17:13.641671 27802 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P be434427641c4420b636978fba6c3f1a: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:13.642530 27802 log.cc:826] T 00000000000000000000000000000000 P be434427641c4420b636978fba6c3f1a: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:13.644333 27802 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P be434427641c4420b636978fba6c3f1a: No bootstrap required, opened a new log
I20260812 06:17:13.646975 27802 raft_consensus.cc:359] T 00000000000000000000000000000000 P be434427641c4420b636978fba6c3f1a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "be434427641c4420b636978fba6c3f1a" member_type: VOTER }
I20260812 06:17:13.647137 27802 raft_consensus.cc:385] T 00000000000000000000000000000000 P be434427641c4420b636978fba6c3f1a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:13.647176 27802 raft_consensus.cc:740] T 00000000000000000000000000000000 P be434427641c4420b636978fba6c3f1a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: be434427641c4420b636978fba6c3f1a, State: Initialized, Role: FOLLOWER
I20260812 06:17:13.647785 27802 consensus_queue.cc:260] T 00000000000000000000000000000000 P be434427641c4420b636978fba6c3f1a [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: "be434427641c4420b636978fba6c3f1a" member_type: VOTER }
I20260812 06:17:13.647949 27802 raft_consensus.cc:399] T 00000000000000000000000000000000 P be434427641c4420b636978fba6c3f1a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:13.648000 27802 raft_consensus.cc:493] T 00000000000000000000000000000000 P be434427641c4420b636978fba6c3f1a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:13.648087 27802 raft_consensus.cc:3060] T 00000000000000000000000000000000 P be434427641c4420b636978fba6c3f1a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:13.648798 27802 raft_consensus.cc:515] T 00000000000000000000000000000000 P be434427641c4420b636978fba6c3f1a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "be434427641c4420b636978fba6c3f1a" member_type: VOTER }
I20260812 06:17:13.649173 27802 leader_election.cc:304] T 00000000000000000000000000000000 P be434427641c4420b636978fba6c3f1a [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: be434427641c4420b636978fba6c3f1a; no voters: 
I20260812 06:17:13.649437 27802 leader_election.cc:290] T 00000000000000000000000000000000 P be434427641c4420b636978fba6c3f1a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:13.649578 27805 raft_consensus.cc:2804] T 00000000000000000000000000000000 P be434427641c4420b636978fba6c3f1a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:13.649844 27805 raft_consensus.cc:697] T 00000000000000000000000000000000 P be434427641c4420b636978fba6c3f1a [term 1 LEADER]: Becoming Leader. State: Replica: be434427641c4420b636978fba6c3f1a, State: Running, Role: LEADER
I20260812 06:17:13.650247 27805 consensus_queue.cc:237] T 00000000000000000000000000000000 P be434427641c4420b636978fba6c3f1a [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: "be434427641c4420b636978fba6c3f1a" member_type: VOTER }
I20260812 06:17:13.650643 27802 sys_catalog.cc:565] T 00000000000000000000000000000000 P be434427641c4420b636978fba6c3f1a [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:13.652120 27807 sys_catalog.cc:455] T 00000000000000000000000000000000 P be434427641c4420b636978fba6c3f1a [sys.catalog]: SysCatalogTable state changed. Reason: New leader be434427641c4420b636978fba6c3f1a. Latest consensus state: current_term: 1 leader_uuid: "be434427641c4420b636978fba6c3f1a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "be434427641c4420b636978fba6c3f1a" member_type: VOTER } }
I20260812 06:17:13.652159 27806 sys_catalog.cc:455] T 00000000000000000000000000000000 P be434427641c4420b636978fba6c3f1a [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "be434427641c4420b636978fba6c3f1a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "be434427641c4420b636978fba6c3f1a" member_type: VOTER } }
I20260812 06:17:13.652319 27806 sys_catalog.cc:458] T 00000000000000000000000000000000 P be434427641c4420b636978fba6c3f1a [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:13.652311 27807 sys_catalog.cc:458] T 00000000000000000000000000000000 P be434427641c4420b636978fba6c3f1a [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:13.652833 27816 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:13.653053 27730 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:13.655027 27816 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:13.659515 27816 catalog_manager.cc:1383] Generated new cluster ID: 2c4c8cb418784542811a65b1d16af287
I20260812 06:17:13.659578 27816 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:13.670181 27816 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:13.670984 27816 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:13.675179 27816 catalog_manager.cc:6092] T 00000000000000000000000000000000 P be434427641c4420b636978fba6c3f1a: Generated new TSK 0
I20260812 06:17:13.675760 27816 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:13.685979 27730 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:13.688604 27828 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:17:13.688746 27730 server_base.cc:1061] running on GCE node
W20260812 06:17:13.688792 27830 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:17:13.688827 27827 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:17:13.689064 27730 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:13.689105 27730 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:17:13.689119 27730 hybrid_clock.cc:648] HybridClock initialized: now 1786515433689119 us; error 0 us; skew 500 ppm
I20260812 06:17:13.690022 27730 webserver.cc:533] Webserver started at http://127.27.20.129:39669/ using document root <none> and password file <none>
I20260812 06:17:13.690191 27730 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:13.690237 27730 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:13.690333 27730 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:13.690722 27730 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root/instance:
uuid: "b5cd51bebfd74721853f22b4efe43ad6"
format_stamp: "Formatted at 2026-08-12 06:17:13 on dist-test-slave-zkpd"
I20260812 06:17:13.692276 27730 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:13.693343 27835 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:17:13.693581 27730 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:13.693673 27730 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root
uuid: "b5cd51bebfd74721853f22b4efe43ad6"
format_stamp: "Formatted at 2026-08-12 06:17:13 on dist-test-slave-zkpd"
I20260812 06:17:13.693771 27730 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-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:17:13.708446 27730 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:13.709303 27730 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:13.709836 27730 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:13.710677 27730 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:13.710757 27730 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:13.710836 27730 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:13.710880 27730 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:13.717764 27730 rpc_server.cc:307] RPC server started. Bound to: 127.27.20.129:36385
I20260812 06:17:13.717801 27901 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.20.129:36385 every 8 connection(s)
I20260812 06:17:13.728456 27902 heartbeater.cc:344] Connected to a master server at 127.27.20.190:42953
I20260812 06:17:13.728710 27902 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:13.729180 27902 heartbeater.cc:507] Master 127.27.20.190:42953 requested a full tablet report, sending...
I20260812 06:17:13.730584 27760 ts_manager.cc:194] Registered new tserver with Master: b5cd51bebfd74721853f22b4efe43ad6 (127.27.20.129:36385)
I20260812 06:17:13.730737 27730 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012315381s
I20260812 06:17:13.732167 27760 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:56344
I20260812 06:17:13.739807 27760 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:56358:
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:17:13.754113 27866 tablet_service.cc:1511] Processing CreateTablet for tablet a52e3f211ccb40b485d4f3444873dd8b (DEFAULT_TABLE table=heavy-update-compaction-test [id=64a03e41bcba47e1b33a8934de1f455d]), partition=
I20260812 06:17:13.754586 27866 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet a52e3f211ccb40b485d4f3444873dd8b. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:13.757196 27916 tablet_bootstrap.cc:492] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Bootstrap starting.
I20260812 06:17:13.758050 27916 tablet_bootstrap.cc:654] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:13.759194 27916 tablet_bootstrap.cc:492] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: No bootstrap required, opened a new log
I20260812 06:17:13.759305 27916 ts_tablet_manager.cc:1403] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:13.759771 27916 raft_consensus.cc:359] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b5cd51bebfd74721853f22b4efe43ad6" member_type: VOTER last_known_addr { host: "127.27.20.129" port: 36385 } }
I20260812 06:17:13.759871 27916 raft_consensus.cc:385] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:13.760006 27916 raft_consensus.cc:740] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b5cd51bebfd74721853f22b4efe43ad6, State: Initialized, Role: FOLLOWER
I20260812 06:17:13.760201 27916 consensus_queue.cc:260] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6 [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: "b5cd51bebfd74721853f22b4efe43ad6" member_type: VOTER last_known_addr { host: "127.27.20.129" port: 36385 } }
I20260812 06:17:13.760330 27916 raft_consensus.cc:399] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:13.760417 27916 raft_consensus.cc:493] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:13.760483 27916 raft_consensus.cc:3060] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:13.761600 27916 raft_consensus.cc:515] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b5cd51bebfd74721853f22b4efe43ad6" member_type: VOTER last_known_addr { host: "127.27.20.129" port: 36385 } }
I20260812 06:17:13.761718 27916 leader_election.cc:304] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6 [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: b5cd51bebfd74721853f22b4efe43ad6; no voters: 
I20260812 06:17:13.761900 27916 leader_election.cc:290] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:13.761997 27918 raft_consensus.cc:2804] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:13.762218 27918 raft_consensus.cc:697] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6 [term 1 LEADER]: Becoming Leader. State: Replica: b5cd51bebfd74721853f22b4efe43ad6, State: Running, Role: LEADER
I20260812 06:17:13.762259 27916 ts_tablet_manager.cc:1434] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:17:13.762420 27918 consensus_queue.cc:237] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6 [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: "b5cd51bebfd74721853f22b4efe43ad6" member_type: VOTER last_known_addr { host: "127.27.20.129" port: 36385 } }
I20260812 06:17:13.762482 27902 heartbeater.cc:499] Master 127.27.20.190:42953 was elected leader, sending a full tablet report...
I20260812 06:17:13.765275 27760 catalog_manager.cc:5719] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6 reported cstate change: term changed from 0 to 1, leader changed from <none> to b5cd51bebfd74721853f22b4efe43ad6 (127.27.20.129). New cstate: current_term: 1 leader_uuid: "b5cd51bebfd74721853f22b4efe43ad6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b5cd51bebfd74721853f22b4efe43ad6" member_type: VOTER last_known_addr { host: "127.27.20.129" port: 36385 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:13.834909 27730 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.061s	user 0.019s	sys 0.009s
I20260812 06:17:13.969107 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushMRSOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=19.054940
I20260812 06:17:14.152010 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushMRSOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.183s	user 0.151s	sys 0.024s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":222,"delete_count":0,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":214,"dirs.run_wall_time_us":1208,"drs_written":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4,"lbm_write_time_us":46211,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":150,"threads_started":1,"update_count":1500}
I20260812 06:17:14.153151 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling LogGCOp(a52e3f211ccb40b485d4f3444873dd8b): free 20743880 bytes of WAL
I20260812 06:17:14.153510 27840 log_reader.cc:385] T a52e3f211ccb40b485d4f3444873dd8b: removed 2 log segments from log reader
I20260812 06:17:14.153597 27840 log.cc:1079] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/a52e3f211ccb40b485d4f3444873dd8b/wal-000000001 (ops 1-6)
I20260812 06:17:14.153698 27840 log.cc:1079] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/a52e3f211ccb40b485d4f3444873dd8b/wal-000000002 (ops 7-11)
I20260812 06:17:14.158671 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: LogGCOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:17:14.159003 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling UndoDeltaBlockGCOp(a52e3f211ccb40b485d4f3444873dd8b): 16411394 bytes on disk
I20260812 06:17:14.159554 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: UndoDeltaBlockGCOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:17:14.160009 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=2.188937
I20260812 06:17:14.181425 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.021s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6649,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:14.182024 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=1.000000
I20260812 06:17:14.337181 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.155s	user 0.105s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1419,"lbm_read_time_us":9099,"lbm_reads_lt_1ms":460,"lbm_write_time_us":24760,"lbm_writes_lt_1ms":443,"mutex_wait_us":379,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4992,"thread_start_us":375,"threads_started":5,"update_count":2000}
I20260812 06:17:14.337783 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=10.126437
I20260812 06:17:14.376075 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.038s	user 0.024s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15352,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:14.376538 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=2.188937
I20260812 06:17:14.387496 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.011s	user 0.009s	sys 0.000s 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:17:14.388170 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=1.000000
I20260812 06:17:14.517966 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.130s	user 0.093s	sys 0.037s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":243,"lbm_read_time_us":9193,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24263,"lbm_writes_lt_1ms":443,"mutex_wait_us":62,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":22784,"update_count":2000}
I20260812 06:17:14.518575 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=10.126437
I20260812 06:17:14.564546 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.046s	user 0.018s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14948,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:14.565092 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=2.188937
I20260812 06:17:14.577045 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4471,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:14.577592 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=1.000000
I20260812 06:17:14.707190 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.129s	user 0.105s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":344,"lbm_read_time_us":9048,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25177,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":20096,"update_count":2000}
I20260812 06:17:14.707836 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=10.126437
I20260812 06:17:14.759850 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.052s	user 0.025s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14874,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:14.760462 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=2.188937
I20260812 06:17:14.772400 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4525,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:14.772821 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=1.000000
I20260812 06:17:14.918239 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.145s	user 0.108s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1281,"lbm_read_time_us":11284,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22558,"lbm_writes_lt_1ms":443,"mutex_wait_us":576,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:17:14.919054 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=10.126437
I20260812 06:17:14.958564 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.039s	user 0.029s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17081,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":1500}
I20260812 06:17:14.959020 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=2.188937
I20260812 06:17:14.969589 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3876,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:14.970270 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=1.000000
I20260812 06:17:15.093405 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.123s	user 0.105s	sys 0.018s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":302,"lbm_read_time_us":8261,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25198,"lbm_writes_lt_1ms":443,"mutex_wait_us":52,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2000}
I20260812 06:17:15.093952 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=10.126437
I20260812 06:17:15.140125 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.046s	user 0.021s	sys 0.021s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18190,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:15.140585 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=2.188937
I20260812 06:17:15.151669 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3961,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:15.152418 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=1.000000
I20260812 06:17:15.274796 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.122s	user 0.110s	sys 0.012s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":68,"lbm_read_time_us":7325,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23176,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":2000}
I20260812 06:17:15.275454 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=10.126437
I20260812 06:17:15.323699 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.048s	user 0.022s	sys 0.023s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17647,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:15.324236 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=2.188937
I20260812 06:17:15.334975 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4244,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:15.335404 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushMRSOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=1.000000
I20260812 06:17:15.379364 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushMRSOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.044s	user 0.035s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":180,"dirs.run_wall_time_us":1287,"drs_written":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2016,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:15.380358 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling LogGCOp(a52e3f211ccb40b485d4f3444873dd8b): free 112692367 bytes of WAL
I20260812 06:17:15.380636 27840 log_reader.cc:385] T a52e3f211ccb40b485d4f3444873dd8b: removed 11 log segments from log reader
I20260812 06:17:15.380709 27840 log.cc:1079] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/a52e3f211ccb40b485d4f3444873dd8b/wal-000000003 (ops 12-16)
I20260812 06:17:15.380764 27840 log.cc:1079] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/a52e3f211ccb40b485d4f3444873dd8b/wal-000000004 (ops 17-21)
I20260812 06:17:15.380821 27840 log.cc:1079] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/a52e3f211ccb40b485d4f3444873dd8b/wal-000000005 (ops 22-26)
I20260812 06:17:15.380867 27840 log.cc:1079] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/a52e3f211ccb40b485d4f3444873dd8b/wal-000000006 (ops 27-31)
I20260812 06:17:15.380915 27840 log.cc:1079] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/a52e3f211ccb40b485d4f3444873dd8b/wal-000000007 (ops 32-36)
I20260812 06:17:15.380949 27840 log.cc:1079] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/a52e3f211ccb40b485d4f3444873dd8b/wal-000000008 (ops 37-41)
I20260812 06:17:15.380985 27840 log.cc:1079] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/a52e3f211ccb40b485d4f3444873dd8b/wal-000000009 (ops 42-46)
I20260812 06:17:15.381019 27840 log.cc:1079] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/a52e3f211ccb40b485d4f3444873dd8b/wal-000000010 (ops 47-51)
I20260812 06:17:15.381054 27840 log.cc:1079] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/a52e3f211ccb40b485d4f3444873dd8b/wal-000000011 (ops 52-56)
I20260812 06:17:15.381088 27840 log.cc:1079] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/a52e3f211ccb40b485d4f3444873dd8b/wal-000000012 (ops 57-61)
I20260812 06:17:15.381124 27840 log.cc:1079] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/a52e3f211ccb40b485d4f3444873dd8b/wal-000000013 (ops 62-66)
I20260812 06:17:15.406325 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: LogGCOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.026s	user 0.003s	sys 0.020s Metrics: {}
I20260812 06:17:15.406718 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling UndoDeltaBlockGCOp(a52e3f211ccb40b485d4f3444873dd8b): 446 bytes on disk
I20260812 06:17:15.407162 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: UndoDeltaBlockGCOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:17:15.407716 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=3.181125
I20260812 06:17:15.421993 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.014s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4556,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:15.422463 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=2.188937
I20260812 06:17:15.432257 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3897,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:15.432754 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=1.000000
I20260812 06:17:15.637519 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.205s	user 0.141s	sys 0.064s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877328,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":153,"lbm_read_time_us":14792,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33869,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":75,"threads_started":1,"update_count":3000}
I20260812 06:17:15.637956 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=14.095187
I20260812 06:17:15.696039 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.058s	user 0.046s	sys 0.008s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":24150,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:15.696641 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=1.000000
I20260812 06:17:15.833065 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.136s	user 0.087s	sys 0.048s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672160,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":571,"lbm_read_time_us":11356,"lbm_reads_lt_1ms":463,"lbm_write_time_us":21378,"lbm_writes_lt_1ms":443,"mutex_wait_us":276,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":2000}
I20260812 06:17:15.833698 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=10.126437
I20260812 06:17:15.864034 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.030s	user 0.030s	sys 0.000s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13108,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:15.864477 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=2.188937
I20260812 06:17:15.877408 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4682,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:15.877914 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=1.000000
I20260812 06:17:16.009794 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.132s	user 0.095s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":111,"lbm_read_time_us":7625,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26504,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2000}
I20260812 06:17:16.010522 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=10.126437
I20260812 06:17:16.044740 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.034s	user 0.025s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14507,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:16.045238 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=2.188937
I20260812 06:17:16.063294 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.018s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6137,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.063983 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=1.000000
I20260812 06:17:16.201023 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.137s	user 0.110s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1164,"lbm_read_time_us":9493,"lbm_reads_lt_1ms":468,"lbm_write_time_us":26071,"lbm_writes_lt_1ms":443,"mutex_wait_us":29,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16768,"update_count":2000}
I20260812 06:17:16.201723 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=10.126437
I20260812 06:17:16.244204 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.042s	user 0.032s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19042,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:16.244702 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=2.188937
I20260812 06:17:16.254791 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3854,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.255399 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=1.000000
I20260812 06:17:16.388414 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.133s	user 0.109s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":311,"lbm_read_time_us":9300,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25555,"lbm_writes_lt_1ms":443,"mutex_wait_us":33,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":2000}
I20260812 06:17:16.389034 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=10.126437
I20260812 06:17:16.443590 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.054s	user 0.016s	sys 0.029s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17083,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:16.444123 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=2.188937
I20260812 06:17:16.454901 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4202,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.455376 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=1.000000
I20260812 06:17:16.613106 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.158s	user 0.098s	sys 0.060s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672275,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":217,"lbm_read_time_us":11542,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27196,"lbm_writes_lt_1ms":443,"mutex_wait_us":53,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2000}
I20260812 06:17:16.616329 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=10.126437
I20260812 06:17:16.656711 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.040s	user 0.031s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19702,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:16.657271 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=2.188937
I20260812 06:17:16.668471 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4285,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.669144 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=1.000000
I20260812 06:17:16.800725 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.131s	user 0.105s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":181,"lbm_read_time_us":8127,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26380,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":2000}
I20260812 06:17:16.801338 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=11.118625
I20260812 06:17:16.837965 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.036s	user 0.026s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15664,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:16.838618 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=2.188937
I20260812 06:17:16.850716 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4503,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:16.851286 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushMRSOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=1.000000
I20260812 06:17:16.878572 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushMRSOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.027s	user 0.022s	sys 0.003s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":196,"dirs.run_wall_time_us":1210,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1829,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:16.879334 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling LogGCOp(a52e3f211ccb40b485d4f3444873dd8b): free 124257190 bytes of WAL
I20260812 06:17:16.879590 27840 log_reader.cc:385] T a52e3f211ccb40b485d4f3444873dd8b: removed 12 log segments from log reader
I20260812 06:17:16.879649 27840 log.cc:1079] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/a52e3f211ccb40b485d4f3444873dd8b/wal-000000014 (ops 67-71)
I20260812 06:17:16.879688 27840 log.cc:1079] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/a52e3f211ccb40b485d4f3444873dd8b/wal-000000015 (ops 72-76)
I20260812 06:17:16.879720 27840 log.cc:1079] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/a52e3f211ccb40b485d4f3444873dd8b/wal-000000016 (ops 77-81)
I20260812 06:17:16.879755 27840 log.cc:1079] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/a52e3f211ccb40b485d4f3444873dd8b/wal-000000017 (ops 82-86)
I20260812 06:17:16.879778 27840 log.cc:1079] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/a52e3f211ccb40b485d4f3444873dd8b/wal-000000018 (ops 87-91)
I20260812 06:17:16.879801 27840 log.cc:1079] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/a52e3f211ccb40b485d4f3444873dd8b/wal-000000019 (ops 92-96)
I20260812 06:17:16.879827 27840 log.cc:1079] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/a52e3f211ccb40b485d4f3444873dd8b/wal-000000020 (ops 97-100)
I20260812 06:17:16.879860 27840 log.cc:1079] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/a52e3f211ccb40b485d4f3444873dd8b/wal-000000021 (ops 101-105)
I20260812 06:17:16.879925 27840 log.cc:1079] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/a52e3f211ccb40b485d4f3444873dd8b/wal-000000022 (ops 106-110)
I20260812 06:17:16.879959 27840 log.cc:1079] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/a52e3f211ccb40b485d4f3444873dd8b/wal-000000023 (ops 111-115)
I20260812 06:17:16.879982 27840 log.cc:1079] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/a52e3f211ccb40b485d4f3444873dd8b/wal-000000024 (ops 116-120)
I20260812 06:17:16.880004 27840 log.cc:1079] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/a52e3f211ccb40b485d4f3444873dd8b/wal-000000025 (ops 121-125)
I20260812 06:17:16.907728 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: LogGCOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.028s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:17:16.908243 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=2.188937
I20260812 06:17:16.924561 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.016s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4419,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.924984 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=2.188937
I20260812 06:17:16.935637 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4378,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.936105 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling UndoDeltaBlockGCOp(a52e3f211ccb40b485d4f3444873dd8b): 472 bytes on disk
I20260812 06:17:16.936545 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: UndoDeltaBlockGCOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:17:16.937413 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=1.000000
I20260812 06:17:17.114807 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.177s	user 0.140s	sys 0.036s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877330,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":659,"lbm_read_time_us":12983,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34812,"lbm_writes_lt_1ms":643,"mutex_wait_us":338,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":15488,"thread_start_us":77,"threads_started":1,"update_count":3000}
I20260812 06:17:17.115507 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=14.095187
I20260812 06:17:17.170389 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.055s	user 0.025s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23380,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:17.170835 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=2.188937
I20260812 06:17:17.181772 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4095,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:17.182229 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=1.000000
I20260812 06:17:17.341279 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.159s	user 0.115s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":160,"lbm_read_time_us":10999,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29940,"lbm_writes_lt_1ms":543,"mutex_wait_us":34,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2500}
I20260812 06:17:17.342790 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=12.110812
I20260812 06:17:17.381731 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.039s	user 0.029s	sys 0.008s Metrics: {"bytes_written":13620266,"delete_count":0,"lbm_write_time_us":17218,"lbm_writes_lt_1ms":335,"reinsert_count":0,"update_count":1660}
I20260812 06:17:17.382295 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=1.196750
I20260812 06:17:17.398458 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.015s	user 0.007s	sys 0.003s Metrics: {"bytes_written":2789855,"delete_count":0,"lbm_write_time_us":4216,"lbm_writes_lt_1ms":71,"reinsert_count":0,"update_count":340}
I20260812 06:17:17.399271 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=1.000000
I20260812 06:17:17.557678 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.158s	user 0.109s	sys 0.047s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672249,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":134,"lbm_read_time_us":9954,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27382,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":85120,"update_count":2000}
I20260812 06:17:17.558370 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=14.095187
I20260812 06:17:17.609067 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.050s	user 0.027s	sys 0.016s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19698,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:17.609704 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=2.188937
I20260812 06:17:17.632531 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.023s	user 0.010s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4799,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:17.633049 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=1.000000
I20260812 06:17:17.811239 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.178s	user 0.115s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":264,"lbm_read_time_us":12598,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30925,"lbm_writes_lt_1ms":543,"mutex_wait_us":60,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11136,"update_count":2500}
I20260812 06:17:17.811918 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=14.095187
I20260812 06:17:17.863873 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.052s	user 0.033s	sys 0.012s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":21711,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:17.864460 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=2.188937
I20260812 06:17:17.875613 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.011s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4196,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:17.876134 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=1.000000
I20260812 06:17:18.048400 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.172s	user 0.129s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":459,"lbm_read_time_us":11914,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29463,"lbm_writes_lt_1ms":543,"mutex_wait_us":67,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":2500}
I20260812 06:17:18.049189 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=11.118625
I20260812 06:17:18.084414 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.035s	user 0.026s	sys 0.008s Metrics: {"bytes_written":12717738,"delete_count":0,"lbm_write_time_us":14776,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:18.085100 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=2.188937
I20260812 06:17:18.100965 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.016s	user 0.009s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5111,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:18.101491 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=1.000000
I20260812 06:17:18.232040 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.130s	user 0.102s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672271,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":825,"lbm_read_time_us":7176,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23486,"lbm_writes_lt_1ms":443,"mutex_wait_us":44,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":114432,"update_count":2000}
I20260812 06:17:18.232935 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=14.095187
I20260812 06:17:18.285422 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.052s	user 0.028s	sys 0.021s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22188,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:18.285971 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=2.188937
I20260812 06:17:18.297099 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3909,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:18.297610 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushMRSOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=1.000000
I20260812 06:17:18.328946 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushMRSOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.031s	user 0.026s	sys 0.004s Metrics: {"bytes_written":1234475,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":228,"dirs.run_wall_time_us":1363,"drs_written":1,"lbm_read_time_us":80,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1666,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30,"spinlock_wait_cycles":1920}
I20260812 06:17:18.329631 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling LogGCOp(a52e3f211ccb40b485d4f3444873dd8b): free 120553630 bytes of WAL
I20260812 06:17:18.329862 27840 log_reader.cc:385] T a52e3f211ccb40b485d4f3444873dd8b: removed 12 log segments from log reader
I20260812 06:17:18.329924 27840 log.cc:1079] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/a52e3f211ccb40b485d4f3444873dd8b/wal-000000026 (ops 126-130)
I20260812 06:17:18.329977 27840 log.cc:1079] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/a52e3f211ccb40b485d4f3444873dd8b/wal-000000027 (ops 131-135)
I20260812 06:17:18.330035 27840 log.cc:1079] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/a52e3f211ccb40b485d4f3444873dd8b/wal-000000028 (ops 136-140)
I20260812 06:17:18.330076 27840 log.cc:1079] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/a52e3f211ccb40b485d4f3444873dd8b/wal-000000029 (ops 141-144)
I20260812 06:17:18.330111 27840 log.cc:1079] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/a52e3f211ccb40b485d4f3444873dd8b/wal-000000030 (ops 145-149)
I20260812 06:17:18.330148 27840 log.cc:1079] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/a52e3f211ccb40b485d4f3444873dd8b/wal-000000031 (ops 150-154)
I20260812 06:17:18.330184 27840 log.cc:1079] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/a52e3f211ccb40b485d4f3444873dd8b/wal-000000032 (ops 155-158)
I20260812 06:17:18.330221 27840 log.cc:1079] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/a52e3f211ccb40b485d4f3444873dd8b/wal-000000033 (ops 159-163)
I20260812 06:17:18.330257 27840 log.cc:1079] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/a52e3f211ccb40b485d4f3444873dd8b/wal-000000034 (ops 164-168)
I20260812 06:17:18.330294 27840 log.cc:1079] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/a52e3f211ccb40b485d4f3444873dd8b/wal-000000035 (ops 169-173)
I20260812 06:17:18.330330 27840 log.cc:1079] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/a52e3f211ccb40b485d4f3444873dd8b/wal-000000036 (ops 174-178)
I20260812 06:17:18.330366 27840 log.cc:1079] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/a52e3f211ccb40b485d4f3444873dd8b/wal-000000037 (ops 179-183)
I20260812 06:17:18.355770 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: LogGCOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.026s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:17:18.356225 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling UndoDeltaBlockGCOp(a52e3f211ccb40b485d4f3444873dd8b): 473 bytes on disk
I20260812 06:17:18.356724 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: UndoDeltaBlockGCOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:17:18.357297 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=3.181125
I20260812 06:17:18.369608 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.012s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":4774,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:18.370024 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling LogGCOp(a52e3f211ccb40b485d4f3444873dd8b): free 12018006 bytes of WAL
I20260812 06:17:18.370247 27840 log_reader.cc:385] T a52e3f211ccb40b485d4f3444873dd8b: removed 1 log segments from log reader
I20260812 06:17:18.370302 27840 log.cc:1079] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/a52e3f211ccb40b485d4f3444873dd8b/wal-000000038 (ops 184-188)
I20260812 06:17:18.373160 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: LogGCOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:17:18.373467 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=2.188937
I20260812 06:17:18.384259 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3822,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:18.384871 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=1.000000
I20260812 06:17:18.579555 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.194s	user 0.146s	sys 0.048s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979739,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":79,"lbm_read_time_us":14061,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39921,"lbm_writes_lt_1ms":743,"mutex_wait_us":23,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":18304,"thread_start_us":80,"threads_started":1,"update_count":3500}
I20260812 06:17:18.580303 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=14.095187
I20260812 06:17:18.627108 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.046s	user 0.030s	sys 0.013s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20159,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:18.627851 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=2.188937
I20260812 06:17:18.656002 27730 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.821s	user 1.748s	sys 0.174s
I20260812 06:17:18.657822 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.030s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7074,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":500}
I20260812 06:17:18.658295 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=2.188937
I20260812 06:17:18.667969 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: FlushDeltaMemStoresOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3944,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:18.668462 27903 maintenance_manager.cc:419] P b5cd51bebfd74721853f22b4efe43ad6: Scheduling MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b): perf score=1.000000
I20260812 06:17:18.708405 27730 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.052s	user 0.005s	sys 0.000s
I20260812 06:17:18.709129 27730 tablet_server.cc:179] TabletServer@127.27.20.129:0 shutting down...
I20260812 06:17:18.803779 27840 maintenance_manager.cc:643] P b5cd51bebfd74721853f22b4efe43ad6: MajorDeltaCompactionOp(a52e3f211ccb40b485d4f3444873dd8b) complete. Timing: real 0.135s	user 0.099s	sys 0.036s Metrics: {"cfile_cache_hit":329,"cfile_cache_hit_bytes":13417395,"cfile_cache_miss":304,"cfile_cache_miss_bytes":15459824,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1443,"lbm_read_time_us":5739,"lbm_reads_lt_1ms":336,"lbm_write_time_us":28775,"lbm_writes_lt_1ms":643,"mutex_wait_us":360,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":65920,"update_count":3000}
I20260812 06:17:18.804543 27730 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:18.804970 27730 tablet_replica.cc:333] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6: stopping tablet replica
I20260812 06:17:18.805227 27730 raft_consensus.cc:2243] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:18.805476 27730 raft_consensus.cc:2272] T a52e3f211ccb40b485d4f3444873dd8b P b5cd51bebfd74721853f22b4efe43ad6 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:18.821530 27730 tablet_server.cc:196] TabletServer@127.27.20.129:0 shutdown complete.
I20260812 06:17:18.857240 27730 master.cc:562] Master@127.27.20.190:42953 shutting down...
I20260812 06:17:18.860996 27730 raft_consensus.cc:2243] T 00000000000000000000000000000000 P be434427641c4420b636978fba6c3f1a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:18.861159 27730 raft_consensus.cc:2272] T 00000000000000000000000000000000 P be434427641c4420b636978fba6c3f1a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:18.861217 27730 tablet_replica.cc:333] T 00000000000000000000000000000000 P be434427641c4420b636978fba6c3f1a: stopping tablet replica
I20260812 06:17:18.873400 27730 master.cc:584] Master@127.27.20.190:42953 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5368 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:18.961984 27730 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.27.20.190:45753
I20260812 06:17:18.962332 27730 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:18.964202 27936 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:17:18.964347 27935 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:17:18.964414 27730 server_base.cc:1061] running on GCE node
W20260812 06:17:18.964202 27938 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:17:18.964666 27730 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:18.964706 27730 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:17:18.964721 27730 hybrid_clock.cc:648] HybridClock initialized: now 1786515438964722 us; error 0 us; skew 500 ppm
I20260812 06:17:18.965597 27730 webserver.cc:533] Webserver started at http://127.27.20.190:43579/ using document root <none> and password file <none>
I20260812 06:17:18.965771 27730 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:18.965834 27730 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:18.965929 27730 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:18.966320 27730 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/master-0-root/instance:
uuid: "04f9a665712e4546bc3cf15bdf49bc3a"
format_stamp: "Formatted at 2026-08-12 06:17:18 on dist-test-slave-zkpd"
I20260812 06:17:18.967813 27730 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:18.968791 27944 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:17:18.969008 27730 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:18.969101 27730 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/master-0-root
uuid: "04f9a665712e4546bc3cf15bdf49bc3a"
format_stamp: "Formatted at 2026-08-12 06:17:18 on dist-test-slave-zkpd"
I20260812 06:17:18.969187 27730 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-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:17:18.994045 27730 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:18.994445 27730 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:18.998732 27730 rpc_server.cc:307] RPC server started. Bound to: 127.27.20.190:45753
I20260812 06:17:19.001937 28005 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.20.190:45753 every 8 connection(s)
I20260812 06:17:19.009804 28007 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:17:19.011686 28007 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 04f9a665712e4546bc3cf15bdf49bc3a: Bootstrap starting.
I20260812 06:17:19.012471 28007 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 04f9a665712e4546bc3cf15bdf49bc3a: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:19.013487 28007 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 04f9a665712e4546bc3cf15bdf49bc3a: No bootstrap required, opened a new log
I20260812 06:17:19.013911 28007 raft_consensus.cc:359] T 00000000000000000000000000000000 P 04f9a665712e4546bc3cf15bdf49bc3a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "04f9a665712e4546bc3cf15bdf49bc3a" member_type: VOTER }
I20260812 06:17:19.013996 28007 raft_consensus.cc:385] T 00000000000000000000000000000000 P 04f9a665712e4546bc3cf15bdf49bc3a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:19.014017 28007 raft_consensus.cc:740] T 00000000000000000000000000000000 P 04f9a665712e4546bc3cf15bdf49bc3a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 04f9a665712e4546bc3cf15bdf49bc3a, State: Initialized, Role: FOLLOWER
I20260812 06:17:19.014168 28007 consensus_queue.cc:260] T 00000000000000000000000000000000 P 04f9a665712e4546bc3cf15bdf49bc3a [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: "04f9a665712e4546bc3cf15bdf49bc3a" member_type: VOTER }
I20260812 06:17:19.014240 28007 raft_consensus.cc:399] T 00000000000000000000000000000000 P 04f9a665712e4546bc3cf15bdf49bc3a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:19.014268 28007 raft_consensus.cc:493] T 00000000000000000000000000000000 P 04f9a665712e4546bc3cf15bdf49bc3a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:19.014333 28007 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 04f9a665712e4546bc3cf15bdf49bc3a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:19.015012 28007 raft_consensus.cc:515] T 00000000000000000000000000000000 P 04f9a665712e4546bc3cf15bdf49bc3a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "04f9a665712e4546bc3cf15bdf49bc3a" member_type: VOTER }
I20260812 06:17:19.015156 28007 leader_election.cc:304] T 00000000000000000000000000000000 P 04f9a665712e4546bc3cf15bdf49bc3a [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: 04f9a665712e4546bc3cf15bdf49bc3a; no voters: 
I20260812 06:17:19.015367 28007 leader_election.cc:290] T 00000000000000000000000000000000 P 04f9a665712e4546bc3cf15bdf49bc3a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:19.015502 28010 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 04f9a665712e4546bc3cf15bdf49bc3a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:19.015763 28010 raft_consensus.cc:697] T 00000000000000000000000000000000 P 04f9a665712e4546bc3cf15bdf49bc3a [term 1 LEADER]: Becoming Leader. State: Replica: 04f9a665712e4546bc3cf15bdf49bc3a, State: Running, Role: LEADER
I20260812 06:17:19.015851 28007 sys_catalog.cc:565] T 00000000000000000000000000000000 P 04f9a665712e4546bc3cf15bdf49bc3a [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:19.015919 28010 consensus_queue.cc:237] T 00000000000000000000000000000000 P 04f9a665712e4546bc3cf15bdf49bc3a [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: "04f9a665712e4546bc3cf15bdf49bc3a" member_type: VOTER }
I20260812 06:17:19.016396 28012 sys_catalog.cc:455] T 00000000000000000000000000000000 P 04f9a665712e4546bc3cf15bdf49bc3a [sys.catalog]: SysCatalogTable state changed. Reason: New leader 04f9a665712e4546bc3cf15bdf49bc3a. Latest consensus state: current_term: 1 leader_uuid: "04f9a665712e4546bc3cf15bdf49bc3a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "04f9a665712e4546bc3cf15bdf49bc3a" member_type: VOTER } }
I20260812 06:17:19.016382 28011 sys_catalog.cc:455] T 00000000000000000000000000000000 P 04f9a665712e4546bc3cf15bdf49bc3a [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "04f9a665712e4546bc3cf15bdf49bc3a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "04f9a665712e4546bc3cf15bdf49bc3a" member_type: VOTER } }
I20260812 06:17:19.016527 28012 sys_catalog.cc:458] T 00000000000000000000000000000000 P 04f9a665712e4546bc3cf15bdf49bc3a [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:19.016604 28011 sys_catalog.cc:458] T 00000000000000000000000000000000 P 04f9a665712e4546bc3cf15bdf49bc3a [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:19.017318 28019 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:19.017974 28019 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:19.018186 27730 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:19.019840 28019 catalog_manager.cc:1383] Generated new cluster ID: 3e3bfb96f12a4302ac1d18260ec64642
I20260812 06:17:19.019922 28019 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:19.033602 28019 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:19.034091 28019 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:19.041132 28019 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 04f9a665712e4546bc3cf15bdf49bc3a: Generated new TSK 0
I20260812 06:17:19.041287 28019 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:19.050463 27730 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:19.052342 28029 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:17:19.052356 28028 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:17:19.052392 28031 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:17:19.052636 27730 server_base.cc:1061] running on GCE node
I20260812 06:17:19.052803 27730 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:19.052841 27730 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:17:19.052856 27730 hybrid_clock.cc:648] HybridClock initialized: now 1786515439052857 us; error 0 us; skew 500 ppm
I20260812 06:17:19.053647 27730 webserver.cc:533] Webserver started at http://127.27.20.129:45017/ using document root <none> and password file <none>
I20260812 06:17:19.053843 27730 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:19.053911 27730 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:19.053992 27730 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:19.054358 27730 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/instance:
uuid: "8016a3306b6c47f3b13b4334c404ced6"
format_stamp: "Formatted at 2026-08-12 06:17:19 on dist-test-slave-zkpd"
I20260812 06:17:19.055791 27730 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:19.056723 28036 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:17:19.056980 27730 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:19.057044 27730 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root
uuid: "8016a3306b6c47f3b13b4334c404ced6"
format_stamp: "Formatted at 2026-08-12 06:17:19 on dist-test-slave-zkpd"
I20260812 06:17:19.057137 27730 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-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:17:19.074409 27730 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:19.074743 27730 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:19.075042 27730 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:19.075480 27730 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:19.075517 27730 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:19.075575 27730 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:19.075618 27730 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:19.079821 27730 rpc_server.cc:307] RPC server started. Bound to: 127.27.20.129:45385
I20260812 06:17:19.081799 28107 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.27.20.129:45385 every 8 connection(s)
I20260812 06:17:19.086066 28108 heartbeater.cc:344] Connected to a master server at 127.27.20.190:45753
I20260812 06:17:19.086169 28108 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:19.086400 28108 heartbeater.cc:507] Master 127.27.20.190:45753 requested a full tablet report, sending...
I20260812 06:17:19.087061 27965 ts_manager.cc:194] Registered new tserver with Master: 8016a3306b6c47f3b13b4334c404ced6 (127.27.20.129:45385)
I20260812 06:17:19.087507 27730 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.006760458s
I20260812 06:17:19.088280 27965 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:54018
I20260812 06:17:19.094828 27965 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:54034:
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:17:19.102885 28066 tablet_service.cc:1511] Processing CreateTablet for tablet 0502e6af28ec4ddaa8b4082a2419065e (DEFAULT_TABLE table=heavy-update-compaction-test [id=4fe331d8a1df4185854ce26827e67bf4]), partition=
I20260812 06:17:19.103101 28066 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 0502e6af28ec4ddaa8b4082a2419065e. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:19.104941 28121 tablet_bootstrap.cc:492] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Bootstrap starting.
I20260812 06:17:19.105849 28121 tablet_bootstrap.cc:654] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:19.106866 28121 tablet_bootstrap.cc:492] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: No bootstrap required, opened a new log
I20260812 06:17:19.106961 28121 ts_tablet_manager.cc:1403] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:17:19.107334 28121 raft_consensus.cc:359] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8016a3306b6c47f3b13b4334c404ced6" member_type: VOTER last_known_addr { host: "127.27.20.129" port: 45385 } }
I20260812 06:17:19.107416 28121 raft_consensus.cc:385] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:19.107477 28121 raft_consensus.cc:740] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 8016a3306b6c47f3b13b4334c404ced6, State: Initialized, Role: FOLLOWER
I20260812 06:17:19.107616 28121 consensus_queue.cc:260] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6 [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: "8016a3306b6c47f3b13b4334c404ced6" member_type: VOTER last_known_addr { host: "127.27.20.129" port: 45385 } }
I20260812 06:17:19.107702 28121 raft_consensus.cc:399] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:19.107784 28121 raft_consensus.cc:493] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:19.107838 28121 raft_consensus.cc:3060] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:19.108587 28121 raft_consensus.cc:515] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8016a3306b6c47f3b13b4334c404ced6" member_type: VOTER last_known_addr { host: "127.27.20.129" port: 45385 } }
I20260812 06:17:19.108774 28121 leader_election.cc:304] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6 [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: 8016a3306b6c47f3b13b4334c404ced6; no voters: 
I20260812 06:17:19.108973 28121 leader_election.cc:290] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:19.109048 28123 raft_consensus.cc:2804] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:19.109310 28123 raft_consensus.cc:697] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6 [term 1 LEADER]: Becoming Leader. State: Replica: 8016a3306b6c47f3b13b4334c404ced6, State: Running, Role: LEADER
I20260812 06:17:19.109318 28121 ts_tablet_manager.cc:1434] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:17:19.109338 28108 heartbeater.cc:499] Master 127.27.20.190:45753 was elected leader, sending a full tablet report...
I20260812 06:17:19.109545 28123 consensus_queue.cc:237] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6 [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: "8016a3306b6c47f3b13b4334c404ced6" member_type: VOTER last_known_addr { host: "127.27.20.129" port: 45385 } }
I20260812 06:17:19.110646 27965 catalog_manager.cc:5719] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6 reported cstate change: term changed from 0 to 1, leader changed from <none> to 8016a3306b6c47f3b13b4334c404ced6 (127.27.20.129). New cstate: current_term: 1 leader_uuid: "8016a3306b6c47f3b13b4334c404ced6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8016a3306b6c47f3b13b4334c404ced6" member_type: VOTER last_known_addr { host: "127.27.20.129" port: 45385 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:19.167357 27730 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.019s	sys 0.003s
I20260812 06:17:19.332451 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling FlushMRSOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=20.047128
I20260812 06:17:19.492043 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: FlushMRSOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.159s	user 0.126s	sys 0.032s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":201,"dirs.run_wall_time_us":871,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":45229,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1500}
I20260812 06:17:19.492668 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling LogGCOp(0502e6af28ec4ddaa8b4082a2419065e): free 20743880 bytes of WAL
I20260812 06:17:19.492892 28042 log_reader.cc:385] T 0502e6af28ec4ddaa8b4082a2419065e: removed 2 log segments from log reader
I20260812 06:17:19.492935 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000001 (ops 1-6)
I20260812 06:17:19.492965 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000002 (ops 7-11)
I20260812 06:17:19.499375 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: LogGCOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.007s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:17:19.499735 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling UndoDeltaBlockGCOp(0502e6af28ec4ddaa8b4082a2419065e): 20513814 bytes on disk
I20260812 06:17:19.500206 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: UndoDeltaBlockGCOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:17:19.500608 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=2.188937
I20260812 06:17:19.522580 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.022s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6326,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:19.523037 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=2.188937
I20260812 06:17:19.533771 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4319,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:19.534204 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling MajorDeltaCompactionOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=1.000000
I20260812 06:17:19.716423 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: MajorDeltaCompactionOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.182s	user 0.143s	sys 0.032s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815803,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":600,"lbm_read_time_us":14066,"lbm_reads_lt_1ms":569,"lbm_write_time_us":33013,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"thread_start_us":304,"threads_started":5,"update_count":2500}
I20260812 06:17:19.717031 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=14.095187
I20260812 06:17:19.766111 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.049s	user 0.025s	sys 0.016s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":18585,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:19.766551 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=2.188937
I20260812 06:17:19.778414 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4222,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:19.778980 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling MajorDeltaCompactionOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=1.000000
I20260812 06:17:19.952378 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: MajorDeltaCompactionOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.173s	user 0.121s	sys 0.044s 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":911,"lbm_read_time_us":11828,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30620,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":716928,"update_count":2500}
I20260812 06:17:19.953068 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=14.095187
I20260812 06:17:20.000231 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.047s	user 0.031s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21296,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:20.000670 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling MajorDeltaCompactionOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=1.000000
I20260812 06:17:20.158308 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: MajorDeltaCompactionOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.157s	user 0.102s	sys 0.049s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713153,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":170,"lbm_read_time_us":10149,"lbm_reads_lt_1ms":467,"lbm_write_time_us":24908,"lbm_writes_lt_1ms":443,"mutex_wait_us":74,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:17:20.159008 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=14.095187
I20260812 06:17:20.210923 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.052s	user 0.036s	sys 0.008s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20790,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:20.211422 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=2.188937
I20260812 06:17:20.223322 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4418,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:20.223769 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling MajorDeltaCompactionOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=1.000000
I20260812 06:17:20.420642 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: MajorDeltaCompactionOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.197s	user 0.146s	sys 0.047s 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":323,"lbm_read_time_us":11532,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31116,"lbm_writes_lt_1ms":543,"mutex_wait_us":65,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2500}
I20260812 06:17:20.421321 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=14.095187
I20260812 06:17:20.475384 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.054s	user 0.026s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24460,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:20.475955 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=2.188937
I20260812 06:17:20.488844 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.013s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5015,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:20.489334 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling MajorDeltaCompactionOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=1.000000
I20260812 06:17:20.666129 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: MajorDeltaCompactionOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.177s	user 0.146s	sys 0.023s 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":233,"lbm_read_time_us":10901,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31929,"lbm_writes_lt_1ms":543,"mutex_wait_us":58,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9344,"update_count":2500}
I20260812 06:17:20.666848 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=14.095187
I20260812 06:17:20.717487 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.050s	user 0.025s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20137,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:20.717998 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=2.188937
I20260812 06:17:20.728804 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4089,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:20.729322 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling FlushMRSOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=1.000000
I20260812 06:17:20.755172 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: FlushMRSOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.026s	user 0.020s	sys 0.003s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":239,"dirs.run_wall_time_us":1423,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1478,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:20.755775 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling LogGCOp(0502e6af28ec4ddaa8b4082a2419065e): free 121006426 bytes of WAL
I20260812 06:17:20.756034 28042 log_reader.cc:385] T 0502e6af28ec4ddaa8b4082a2419065e: removed 12 log segments from log reader
I20260812 06:17:20.756096 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000003 (ops 12-16)
I20260812 06:17:20.756148 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000004 (ops 17-21)
I20260812 06:17:20.756206 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000005 (ops 22-26)
I20260812 06:17:20.756246 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000006 (ops 27-31)
I20260812 06:17:20.756283 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000007 (ops 32-36)
I20260812 06:17:20.756320 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000008 (ops 37-41)
I20260812 06:17:20.756356 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000009 (ops 42-46)
I20260812 06:17:20.756394 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000010 (ops 47-50)
I20260812 06:17:20.756430 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000011 (ops 51-55)
I20260812 06:17:20.756467 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000012 (ops 56-60)
I20260812 06:17:20.756503 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000013 (ops 61-65)
I20260812 06:17:20.756539 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000014 (ops 66-70)
I20260812 06:17:20.783219 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: LogGCOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.027s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:17:20.783659 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling UndoDeltaBlockGCOp(0502e6af28ec4ddaa8b4082a2419065e): 462 bytes on disk
I20260812 06:17:20.784133 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: UndoDeltaBlockGCOp(0502e6af28ec4ddaa8b4082a2419065e) 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:17:20.784586 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=3.181125
I20260812 06:17:20.808110 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.023s	user 0.011s	sys 0.011s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4594,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:20.808514 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=2.188937
I20260812 06:17:20.819167 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4107,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:20.819568 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling MajorDeltaCompactionOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=1.000000
I20260812 06:17:21.084797 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: MajorDeltaCompactionOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.265s	user 0.143s	sys 0.110s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020735,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":881,"lbm_read_time_us":16344,"lbm_reads_lt_1ms":774,"lbm_write_time_us":42178,"lbm_writes_lt_1ms":743,"mutex_wait_us":346,"peak_mem_usage":87969044,"reinsert_count":0,"thread_start_us":82,"threads_started":1,"update_count":3500}
I20260812 06:17:21.085505 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=18.063937
I20260812 06:17:21.161180 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.075s	user 0.027s	sys 0.035s Metrics: {"bytes_written":20512319,"delete_count":0,"lbm_write_time_us":28967,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:17:21.161746 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=2.188937
I20260812 06:17:21.238332 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.076s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4091,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:21.239058 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=3.181125
I20260812 06:17:21.336870 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.098s	user 0.012s	sys 0.003s Metrics: {"bytes_written":4964173,"delete_count":0,"lbm_write_time_us":6215,"lbm_writes_lt_1ms":124,"reinsert_count":0,"update_count":605}
I20260812 06:17:21.337419 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=9.134250
I20260812 06:17:21.440037 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.102s	user 0.021s	sys 0.016s Metrics: {"bytes_written":11240872,"delete_count":0,"lbm_write_time_us":15220,"lbm_writes_lt_1ms":277,"reinsert_count":0,"update_count":1370}
I20260812 06:17:21.440701 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=7.149875
I20260812 06:17:21.540263 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.099s	user 0.016s	sys 0.016s Metrics: {"bytes_written":8410202,"delete_count":0,"lbm_write_time_us":13425,"lbm_writes_lt_1ms":208,"reinsert_count":0,"update_count":1025}
I20260812 06:17:21.541260 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=6.157687
I20260812 06:17:21.638762 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.097s	user 0.015s	sys 0.007s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":9600,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:21.639393 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=6.157687
I20260812 06:17:21.740837 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.101s	user 0.025s	sys 0.000s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10364,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:21.741401 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=7.149875
I20260812 06:17:21.842504 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.101s	user 0.015s	sys 0.004s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":8437,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:17:21.843186 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=10.126437
I20260812 06:17:21.947808 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.104s	user 0.011s	sys 0.020s Metrics: {"bytes_written":11897249,"delete_count":0,"lbm_write_time_us":13972,"lbm_writes_lt_1ms":293,"reinsert_count":0,"update_count":1450}
I20260812 06:17:21.948621 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=7.149875
I20260812 06:17:22.058740 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.110s	user 0.014s	sys 0.012s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":8749,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:17:22.059331 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=10.126437
I20260812 06:17:22.155049 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.096s	user 0.035s	sys 0.005s Metrics: {"bytes_written":11897249,"delete_count":0,"lbm_write_time_us":18653,"lbm_writes_lt_1ms":293,"reinsert_count":0,"update_count":1450}
I20260812 06:17:22.155555 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=3.181125
I20260812 06:17:22.253189 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.097s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4512904,"delete_count":0,"lbm_write_time_us":6417,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:22.253737 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=9.134250
I20260812 06:17:22.352806 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.099s	user 0.010s	sys 0.020s Metrics: {"bytes_written":10666526,"delete_count":0,"lbm_write_time_us":12395,"lbm_writes_lt_1ms":263,"reinsert_count":0,"update_count":1300}
I20260812 06:17:22.353377 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=5.165500
I20260812 06:17:22.396733 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.043s	user 0.017s	sys 0.003s Metrics: {"bytes_written":7179484,"delete_count":0,"lbm_write_time_us":8682,"lbm_writes_lt_1ms":178,"reinsert_count":0,"update_count":875}
I20260812 06:17:22.397545 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=2.188937
I20260812 06:17:22.447147 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.049s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3405238,"delete_count":0,"lbm_write_time_us":3223,"lbm_writes_lt_1ms":86,"reinsert_count":0,"update_count":415}
I20260812 06:17:22.447801 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=5.165500
I20260812 06:17:22.477296 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.029s	user 0.018s	sys 0.004s Metrics: {"bytes_written":7056408,"delete_count":0,"lbm_write_time_us":9309,"lbm_writes_lt_1ms":175,"reinsert_count":0,"update_count":860}
I20260812 06:17:22.477854 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling FlushMRSOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=1.000000
I20260812 06:17:22.512526 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: FlushMRSOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.035s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1521480,"cfile_init":1,"dirs.queue_time_us":228,"dirs.run_cpu_time_us":377,"dirs.run_wall_time_us":4466,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2067,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":37,"thread_start_us":76,"threads_started":1}
I20260812 06:17:22.513536 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling LogGCOp(0502e6af28ec4ddaa8b4082a2419065e): free 149652597 bytes of WAL
I20260812 06:17:22.513821 28042 log_reader.cc:385] T 0502e6af28ec4ddaa8b4082a2419065e: removed 15 log segments from log reader
I20260812 06:17:22.513865 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000015 (ops 71-75)
I20260812 06:17:22.513895 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000016 (ops 76-80)
I20260812 06:17:22.513952 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000017 (ops 81-85)
I20260812 06:17:22.513994 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000018 (ops 86-90)
I20260812 06:17:22.514037 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000019 (ops 91-94)
I20260812 06:17:22.514071 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000020 (ops 95-99)
I20260812 06:17:22.514109 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000021 (ops 100-104)
I20260812 06:17:22.514147 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000022 (ops 105-109)
I20260812 06:17:22.514206 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000023 (ops 110-114)
I20260812 06:17:22.514240 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000024 (ops 115-118)
I20260812 06:17:22.514277 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000025 (ops 119-123)
I20260812 06:17:22.514315 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000026 (ops 124-128)
I20260812 06:17:22.514355 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000027 (ops 129-132)
I20260812 06:17:22.514394 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000028 (ops 133-137)
I20260812 06:17:22.514431 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000029 (ops 138-142)
I20260812 06:17:22.552971 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: LogGCOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.039s	user 0.000s	sys 0.038s Metrics: {}
I20260812 06:17:22.553529 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=6.157687
I20260812 06:17:22.577437 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.024s	user 0.016s	sys 0.004s Metrics: {"bytes_written":7876885,"delete_count":0,"lbm_write_time_us":8999,"lbm_writes_lt_1ms":195,"reinsert_count":0,"update_count":960}
I20260812 06:17:22.577915 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling UndoDeltaBlockGCOp(0502e6af28ec4ddaa8b4082a2419065e): 552 bytes on disk
I20260812 06:17:22.578312 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: UndoDeltaBlockGCOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:17:22.578821 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling MajorDeltaCompactionOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=1.000000
I20260812 06:17:23.665530 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: MajorDeltaCompactionOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 1.087s	user 0.645s	sys 0.395s Metrics: {"cfile_cache_miss":3639,"cfile_cache_miss_bytes":151664100,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":17,"delta_iterators_relevant":17,"dirs.queue_time_us":1035,"lbm_read_time_us":67058,"lbm_reads_lt_1ms":3675,"lbm_write_time_us":200068,"lbm_writes_lt_1ms":3638,"mutex_wait_us":54,"peak_mem_usage":446970968,"reinsert_count":0,"spinlock_wait_cycles":43520,"thread_start_us":449,"threads_started":7,"update_count":17960}
I20260812 06:17:23.666440 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=74.618625
I20260812 06:17:23.874626 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.208s	user 0.134s	sys 0.051s Metrics: {"bytes_written":78274392,"delete_count":0,"lbm_write_time_us":85155,"lbm_writes_lt_1ms":1913,"reinsert_count":0,"update_count":9540}
I20260812 06:17:23.875254 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=14.095187
I20260812 06:17:24.068849 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.193s	user 0.023s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20377,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:24.069639 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=14.095187
I20260812 06:17:24.116043 27730 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.949s	user 1.754s	sys 0.134s
I20260812 06:17:24.275396 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.206s	user 0.033s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23195,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:24.276121 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=2.188937
I20260812 06:17:24.285960 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: FlushDeltaMemStoresOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.010s	user 0.003s	sys 0.006s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3916,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:24.286394 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling FlushMRSOp(0502e6af28ec4ddaa8b4082a2419065e): perf score=1.000000
I20260812 06:17:24.328483 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: FlushMRSOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.042s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1193506,"cfile_init":1,"dirs.queue_time_us":213,"dirs.run_cpu_time_us":245,"dirs.run_wall_time_us":19232,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1338,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29,"thread_start_us":119,"threads_started":1}
I20260812 06:17:24.329161 28109 maintenance_manager.cc:419] P 8016a3306b6c47f3b13b4334c404ced6: Scheduling LogGCOp(0502e6af28ec4ddaa8b4082a2419065e): free 127961379 bytes of WAL
I20260812 06:17:24.329418 28042 log_reader.cc:385] T 0502e6af28ec4ddaa8b4082a2419065e: removed 12 log segments from log reader
I20260812 06:17:24.329484 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000030 (ops 143-147)
I20260812 06:17:24.329579 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000031 (ops 148-152)
I20260812 06:17:24.329638 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000032 (ops 153-157)
I20260812 06:17:24.329684 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000033 (ops 158-162)
I20260812 06:17:24.329766 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000034 (ops 163-167)
I20260812 06:17:24.329841 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000035 (ops 168-172)
I20260812 06:17:24.329882 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000036 (ops 173-177)
I20260812 06:17:24.329926 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000037 (ops 178-182)
I20260812 06:17:24.329967 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000038 (ops 183-187)
I20260812 06:17:24.330009 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000039 (ops 188-192)
I20260812 06:17:24.330051 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000040 (ops 193-197)
I20260812 06:17:24.330092 28042 log.cc:1079] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: Deleting log segment in path: /tmp/dist-test-taskTbwBLj/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515433582941-27730-0/minicluster-data/ts-0-root/wals/0502e6af28ec4ddaa8b4082a2419065e/wal-000000041 (ops 198-202)
I20260812 06:17:24.339387 27730 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.223s	user 0.001s	sys 0.000s
I20260812 06:17:24.339860 27730 tablet_server.cc:179] TabletServer@127.27.20.129:0 shutting down...
I20260812 06:17:24.361158 28042 maintenance_manager.cc:643] P 8016a3306b6c47f3b13b4334c404ced6: LogGCOp(0502e6af28ec4ddaa8b4082a2419065e) complete. Timing: real 0.032s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:17:24.361718 27730 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:24.362002 27730 tablet_replica.cc:333] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6: stopping tablet replica
I20260812 06:17:24.362171 27730 raft_consensus.cc:2243] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:24.362361 27730 raft_consensus.cc:2272] T 0502e6af28ec4ddaa8b4082a2419065e P 8016a3306b6c47f3b13b4334c404ced6 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:24.375402 27730 tablet_server.cc:196] TabletServer@127.27.20.129:0 shutdown complete.
I20260812 06:17:24.378098 27730 master.cc:562] Master@127.27.20.190:45753 shutting down...
I20260812 06:17:24.381359 27730 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 04f9a665712e4546bc3cf15bdf49bc3a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:24.381482 27730 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 04f9a665712e4546bc3cf15bdf49bc3a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:24.381527 27730 tablet_replica.cc:333] T 00000000000000000000000000000000 P 04f9a665712e4546bc3cf15bdf49bc3a: stopping tablet replica
I20260812 06:17:24.393522 27730 master.cc:584] Master@127.27.20.190:45753 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5511 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10881 ms total)

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