[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:18:07.015389 11230 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.10.247.190:37829
I20260812 06:18:07.016391 11230 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:18:07.017052 11230 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:07.023399 11246 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:07.023416 11244 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:07.023599 11230 server_base.cc:1061] running on GCE node
W20260812 06:18:07.023749 11240 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:07.024297 11230 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:07.024394 11230 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:07.024425 11230 hybrid_clock.cc:648] HybridClock initialized: now 1786515487024424 us; error 0 us; skew 500 ppm
I20260812 06:18:07.026165 11230 webserver.cc:533] Webserver started at http://127.10.247.190:43573/ using document root <none> and password file <none>
I20260812 06:18:07.026646 11230 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:07.026701 11230 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:07.026880 11230 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:07.028448 11230 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/master-0-root/instance:
uuid: "048a8cc92dac4592a49fe2d4f13a8dce"
format_stamp: "Formatted at 2026-08-12 06:18:07 on dist-test-slave-2kcd"
I20260812 06:18:07.031769 11230 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.001s	sys 0.001s
I20260812 06:18:07.033762 11256 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:07.034739 11230 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:07.034835 11230 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/master-0-root
uuid: "048a8cc92dac4592a49fe2d4f13a8dce"
format_stamp: "Formatted at 2026-08-12 06:18:07 on dist-test-slave-2kcd"
I20260812 06:18:07.034912 11230 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:07.077052 11230 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:07.077702 11230 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:18:07.077845 11230 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:07.085969 11230 rpc_server.cc:307] RPC server started. Bound to: 127.10.247.190:37829
I20260812 06:18:07.085965 11356 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.247.190:37829 every 8 connection(s)
I20260812 06:18:07.088274 11357 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:07.093650 11357 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 048a8cc92dac4592a49fe2d4f13a8dce: Bootstrap starting.
I20260812 06:18:07.095928 11357 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 048a8cc92dac4592a49fe2d4f13a8dce: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:07.096776 11357 log.cc:826] T 00000000000000000000000000000000 P 048a8cc92dac4592a49fe2d4f13a8dce: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:07.098495 11357 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 048a8cc92dac4592a49fe2d4f13a8dce: No bootstrap required, opened a new log
I20260812 06:18:07.101338 11357 raft_consensus.cc:359] T 00000000000000000000000000000000 P 048a8cc92dac4592a49fe2d4f13a8dce [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "048a8cc92dac4592a49fe2d4f13a8dce" member_type: VOTER }
I20260812 06:18:07.101500 11357 raft_consensus.cc:385] T 00000000000000000000000000000000 P 048a8cc92dac4592a49fe2d4f13a8dce [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:07.101548 11357 raft_consensus.cc:740] T 00000000000000000000000000000000 P 048a8cc92dac4592a49fe2d4f13a8dce [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 048a8cc92dac4592a49fe2d4f13a8dce, State: Initialized, Role: FOLLOWER
I20260812 06:18:07.102077 11357 consensus_queue.cc:260] T 00000000000000000000000000000000 P 048a8cc92dac4592a49fe2d4f13a8dce [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: "048a8cc92dac4592a49fe2d4f13a8dce" member_type: VOTER }
I20260812 06:18:07.102205 11357 raft_consensus.cc:399] T 00000000000000000000000000000000 P 048a8cc92dac4592a49fe2d4f13a8dce [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:07.102245 11357 raft_consensus.cc:493] T 00000000000000000000000000000000 P 048a8cc92dac4592a49fe2d4f13a8dce [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:07.102337 11357 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 048a8cc92dac4592a49fe2d4f13a8dce [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:07.103086 11357 raft_consensus.cc:515] T 00000000000000000000000000000000 P 048a8cc92dac4592a49fe2d4f13a8dce [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "048a8cc92dac4592a49fe2d4f13a8dce" member_type: VOTER }
I20260812 06:18:07.103477 11357 leader_election.cc:304] T 00000000000000000000000000000000 P 048a8cc92dac4592a49fe2d4f13a8dce [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: 048a8cc92dac4592a49fe2d4f13a8dce; no voters: 
I20260812 06:18:07.103750 11357 leader_election.cc:290] T 00000000000000000000000000000000 P 048a8cc92dac4592a49fe2d4f13a8dce [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:07.103899 11366 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 048a8cc92dac4592a49fe2d4f13a8dce [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:07.104166 11366 raft_consensus.cc:697] T 00000000000000000000000000000000 P 048a8cc92dac4592a49fe2d4f13a8dce [term 1 LEADER]: Becoming Leader. State: Replica: 048a8cc92dac4592a49fe2d4f13a8dce, State: Running, Role: LEADER
I20260812 06:18:07.104590 11366 consensus_queue.cc:237] T 00000000000000000000000000000000 P 048a8cc92dac4592a49fe2d4f13a8dce [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: "048a8cc92dac4592a49fe2d4f13a8dce" member_type: VOTER }
I20260812 06:18:07.104944 11357 sys_catalog.cc:565] T 00000000000000000000000000000000 P 048a8cc92dac4592a49fe2d4f13a8dce [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:07.106676 11368 sys_catalog.cc:455] T 00000000000000000000000000000000 P 048a8cc92dac4592a49fe2d4f13a8dce [sys.catalog]: SysCatalogTable state changed. Reason: New leader 048a8cc92dac4592a49fe2d4f13a8dce. Latest consensus state: current_term: 1 leader_uuid: "048a8cc92dac4592a49fe2d4f13a8dce" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "048a8cc92dac4592a49fe2d4f13a8dce" member_type: VOTER } }
I20260812 06:18:07.106719 11367 sys_catalog.cc:455] T 00000000000000000000000000000000 P 048a8cc92dac4592a49fe2d4f13a8dce [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "048a8cc92dac4592a49fe2d4f13a8dce" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "048a8cc92dac4592a49fe2d4f13a8dce" member_type: VOTER } }
I20260812 06:18:07.106838 11368 sys_catalog.cc:458] T 00000000000000000000000000000000 P 048a8cc92dac4592a49fe2d4f13a8dce [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:07.106838 11367 sys_catalog.cc:458] T 00000000000000000000000000000000 P 048a8cc92dac4592a49fe2d4f13a8dce [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:07.107290 11388 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:07.107393 11230 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:07.109630 11388 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:07.114050 11388 catalog_manager.cc:1383] Generated new cluster ID: b575b5031c0e47a6a680e05e0bc85ccd
I20260812 06:18:07.114116 11388 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:07.133363 11388 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:07.134274 11388 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:07.150909 11388 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 048a8cc92dac4592a49fe2d4f13a8dce: Generated new TSK 0
I20260812 06:18:07.151569 11388 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:07.172099 11230 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:07.174841 11405 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:07.174844 11410 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:07.175063 11230 server_base.cc:1061] running on GCE node
W20260812 06:18:07.175187 11407 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:07.175424 11230 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:07.175508 11230 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:07.175544 11230 hybrid_clock.cc:648] HybridClock initialized: now 1786515487175543 us; error 0 us; skew 500 ppm
I20260812 06:18:07.176496 11230 webserver.cc:533] Webserver started at http://127.10.247.129:39447/ using document root <none> and password file <none>
I20260812 06:18:07.176671 11230 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:07.176738 11230 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:07.176837 11230 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:07.177218 11230 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/instance:
uuid: "ead6084830f946a8ab46d990b9e18f1c"
format_stamp: "Formatted at 2026-08-12 06:18:07 on dist-test-slave-2kcd"
I20260812 06:18:07.178735 11230 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:07.179745 11423 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:07.180001 11230 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:07.180074 11230 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root
uuid: "ead6084830f946a8ab46d990b9e18f1c"
format_stamp: "Formatted at 2026-08-12 06:18:07 on dist-test-slave-2kcd"
I20260812 06:18:07.180158 11230 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:07.201175 11230 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:07.201610 11230 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:07.202127 11230 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:07.203022 11230 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:07.203076 11230 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:07.203140 11230 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:07.203181 11230 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:07.209975 11230 rpc_server.cc:307] RPC server started. Bound to: 127.10.247.129:45941
I20260812 06:18:07.210022 11539 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.247.129:45941 every 8 connection(s)
I20260812 06:18:07.220088 11540 heartbeater.cc:344] Connected to a master server at 127.10.247.190:37829
I20260812 06:18:07.220335 11540 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:07.220845 11540 heartbeater.cc:507] Master 127.10.247.190:37829 requested a full tablet report, sending...
I20260812 06:18:07.222175 11281 ts_manager.cc:194] Registered new tserver with Master: ead6084830f946a8ab46d990b9e18f1c (127.10.247.129:45941)
I20260812 06:18:07.222976 11230 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012399692s
I20260812 06:18:07.223366 11281 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:48236
I20260812 06:18:07.233088 11281 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:48240:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:07.247689 11469 tablet_service.cc:1511] Processing CreateTablet for tablet 3d27dea4bfc947e88dfeb9e5cf61b830 (DEFAULT_TABLE table=heavy-update-compaction-test [id=1721387f2b6a45e680113437ded02b52]), partition=
I20260812 06:18:07.248152 11469 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 3d27dea4bfc947e88dfeb9e5cf61b830. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:07.250808 11565 tablet_bootstrap.cc:492] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Bootstrap starting.
I20260812 06:18:07.251812 11565 tablet_bootstrap.cc:654] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:07.253332 11565 tablet_bootstrap.cc:492] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: No bootstrap required, opened a new log
I20260812 06:18:07.253420 11565 ts_tablet_manager.cc:1403] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:18:07.253947 11565 raft_consensus.cc:359] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ead6084830f946a8ab46d990b9e18f1c" member_type: VOTER last_known_addr { host: "127.10.247.129" port: 45941 } }
I20260812 06:18:07.254050 11565 raft_consensus.cc:385] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:07.254072 11565 raft_consensus.cc:740] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ead6084830f946a8ab46d990b9e18f1c, State: Initialized, Role: FOLLOWER
I20260812 06:18:07.254233 11565 consensus_queue.cc:260] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c [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: "ead6084830f946a8ab46d990b9e18f1c" member_type: VOTER last_known_addr { host: "127.10.247.129" port: 45941 } }
I20260812 06:18:07.254338 11565 raft_consensus.cc:399] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:07.254395 11565 raft_consensus.cc:493] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:07.254462 11565 raft_consensus.cc:3060] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:07.255424 11565 raft_consensus.cc:515] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ead6084830f946a8ab46d990b9e18f1c" member_type: VOTER last_known_addr { host: "127.10.247.129" port: 45941 } }
I20260812 06:18:07.255574 11565 leader_election.cc:304] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c [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: ead6084830f946a8ab46d990b9e18f1c; no voters: 
I20260812 06:18:07.255829 11565 leader_election.cc:290] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:07.255927 11567 raft_consensus.cc:2804] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:07.256206 11565 ts_tablet_manager.cc:1434] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:07.256189 11567 raft_consensus.cc:697] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c [term 1 LEADER]: Becoming Leader. State: Replica: ead6084830f946a8ab46d990b9e18f1c, State: Running, Role: LEADER
I20260812 06:18:07.256413 11540 heartbeater.cc:499] Master 127.10.247.190:37829 was elected leader, sending a full tablet report...
I20260812 06:18:07.256536 11567 consensus_queue.cc:237] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c [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: "ead6084830f946a8ab46d990b9e18f1c" member_type: VOTER last_known_addr { host: "127.10.247.129" port: 45941 } }
I20260812 06:18:07.259640 11281 catalog_manager.cc:5719] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c reported cstate change: term changed from 0 to 1, leader changed from <none> to ead6084830f946a8ab46d990b9e18f1c (127.10.247.129). New cstate: current_term: 1 leader_uuid: "ead6084830f946a8ab46d990b9e18f1c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ead6084830f946a8ab46d990b9e18f1c" member_type: VOTER last_known_addr { host: "127.10.247.129" port: 45941 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:07.324179 11230 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.009s	sys 0.017s
I20260812 06:18:07.461038 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushMRSOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=19.054940
I20260812 06:18:07.620164 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushMRSOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.159s	user 0.123s	sys 0.032s Metrics: {"bytes_written":9517852,"cfile_init":1,"compiler_manager_pool.queue_time_us":219,"delete_count":0,"dirs.queue_time_us":44,"dirs.run_cpu_time_us":227,"dirs.run_wall_time_us":992,"drs_written":1,"lbm_read_time_us":116,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39395,"lbm_writes_lt_1ms":689,"mutex_wait_us":218,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":140416,"thread_start_us":133,"threads_started":1,"update_count":1160}
I20260812 06:18:07.621654 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling LogGCOp(3d27dea4bfc947e88dfeb9e5cf61b830): free 20743831 bytes of WAL
I20260812 06:18:07.622102 11429 log_reader.cc:385] T 3d27dea4bfc947e88dfeb9e5cf61b830: removed 2 log segments from log reader
I20260812 06:18:07.622265 11429 log.cc:1079] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3d27dea4bfc947e88dfeb9e5cf61b830/wal-000000001 (ops 1-6)
I20260812 06:18:07.622402 11429 log.cc:1079] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3d27dea4bfc947e88dfeb9e5cf61b830/wal-000000002 (ops 7-11)
I20260812 06:18:07.628717 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: LogGCOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.007s	user 0.001s	sys 0.004s Metrics: {}
I20260812 06:18:07.629254 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling UndoDeltaBlockGCOp(3d27dea4bfc947e88dfeb9e5cf61b830): 16411394 bytes on disk
I20260812 06:18:07.630023 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: UndoDeltaBlockGCOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":95,"lbm_reads_lt_1ms":4}
I20260812 06:18:07.630698 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=2.188937
I20260812 06:18:07.652066 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.021s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3200109,"delete_count":0,"lbm_write_time_us":5036,"lbm_writes_lt_1ms":81,"reinsert_count":0,"update_count":390}
I20260812 06:18:07.652565 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=2.188937
I20260812 06:18:07.662074 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3590,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:07.662524 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=1.000000
I20260812 06:18:07.794070 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.131s	user 0.115s	sys 0.011s Metrics: {"cfile_cache_miss":433,"cfile_cache_miss_bytes":20672366,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":612,"lbm_read_time_us":9041,"lbm_reads_lt_1ms":469,"lbm_write_time_us":22907,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":324,"threads_started":5,"update_count":2000}
I20260812 06:18:07.794622 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=10.126437
I20260812 06:18:07.844656 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.050s	user 0.020s	sys 0.021s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18628,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:07.845257 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=2.188937
I20260812 06:18:07.857260 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4153,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:07.857750 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=1.000000
I20260812 06:18:07.982553 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.125s	user 0.088s	sys 0.036s 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":1234,"lbm_read_time_us":7724,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24511,"lbm_writes_lt_1ms":443,"mutex_wait_us":367,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2000}
I20260812 06:18:07.983145 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=10.126437
I20260812 06:18:08.018723 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.035s	user 0.021s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13950,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:08.019330 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=2.188937
I20260812 06:18:08.029903 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.010s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4170,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:08.030458 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=1.000000
I20260812 06:18:08.149775 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.119s	user 0.083s	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":234,"lbm_read_time_us":9774,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22740,"lbm_writes_lt_1ms":443,"mutex_wait_us":80,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2000}
I20260812 06:18:08.150442 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=10.126437
I20260812 06:18:08.194957 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.044s	user 0.027s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16051,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:08.195497 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=2.188937
I20260812 06:18:08.206321 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4111,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:08.206739 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=1.000000
I20260812 06:18:08.353749 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.147s	user 0.100s	sys 0.044s 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":283,"lbm_read_time_us":10931,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26147,"lbm_writes_lt_1ms":443,"mutex_wait_us":20,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2000}
I20260812 06:18:08.354450 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=10.126437
I20260812 06:18:08.400336 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.046s	user 0.022s	sys 0.016s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":19710,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:18:08.400893 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=2.188937
I20260812 06:18:08.416555 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5827,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:08.417202 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=1.000000
I20260812 06:18:08.547804 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.130s	user 0.094s	sys 0.036s 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":172,"lbm_read_time_us":10418,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25118,"lbm_writes_lt_1ms":443,"mutex_wait_us":37,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2000}
I20260812 06:18:08.548378 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=10.126437
I20260812 06:18:08.592607 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.044s	user 0.007s	sys 0.028s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16873,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:08.593071 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=2.188937
I20260812 06:18:08.603811 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.011s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4048,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:08.604403 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=1.000000
I20260812 06:18:08.726877 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.122s	user 0.097s	sys 0.025s 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":653,"lbm_read_time_us":9212,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23159,"lbm_writes_lt_1ms":443,"mutex_wait_us":343,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6144,"update_count":2000}
I20260812 06:18:08.727384 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=10.126437
I20260812 06:18:08.777803 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.050s	user 0.026s	sys 0.014s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14593,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:08.778409 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=2.188937
I20260812 06:18:08.789029 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4112,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:08.789479 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushMRSOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=1.000000
I20260812 06:18:08.831704 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushMRSOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.042s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":199,"dirs.run_wall_time_us":1389,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1619,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:08.832461 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling LogGCOp(3d27dea4bfc947e88dfeb9e5cf61b830): free 112239360 bytes of WAL
I20260812 06:18:08.832683 11429 log_reader.cc:385] T 3d27dea4bfc947e88dfeb9e5cf61b830: removed 11 log segments from log reader
I20260812 06:18:08.832726 11429 log.cc:1079] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3d27dea4bfc947e88dfeb9e5cf61b830/wal-000000003 (ops 12-16)
I20260812 06:18:08.832757 11429 log.cc:1079] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3d27dea4bfc947e88dfeb9e5cf61b830/wal-000000004 (ops 17-21)
I20260812 06:18:08.832840 11429 log.cc:1079] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3d27dea4bfc947e88dfeb9e5cf61b830/wal-000000005 (ops 22-26)
I20260812 06:18:08.832876 11429 log.cc:1079] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3d27dea4bfc947e88dfeb9e5cf61b830/wal-000000006 (ops 27-31)
I20260812 06:18:08.832918 11429 log.cc:1079] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3d27dea4bfc947e88dfeb9e5cf61b830/wal-000000007 (ops 32-36)
I20260812 06:18:08.832988 11429 log.cc:1079] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3d27dea4bfc947e88dfeb9e5cf61b830/wal-000000008 (ops 37-41)
I20260812 06:18:08.833039 11429 log.cc:1079] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3d27dea4bfc947e88dfeb9e5cf61b830/wal-000000009 (ops 42-46)
I20260812 06:18:08.833081 11429 log.cc:1079] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3d27dea4bfc947e88dfeb9e5cf61b830/wal-000000010 (ops 47-51)
I20260812 06:18:08.833118 11429 log.cc:1079] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3d27dea4bfc947e88dfeb9e5cf61b830/wal-000000011 (ops 52-56)
I20260812 06:18:08.833158 11429 log.cc:1079] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3d27dea4bfc947e88dfeb9e5cf61b830/wal-000000012 (ops 57-60)
I20260812 06:18:08.833200 11429 log.cc:1079] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3d27dea4bfc947e88dfeb9e5cf61b830/wal-000000013 (ops 61-65)
I20260812 06:18:08.856750 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: LogGCOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.024s	user 0.001s	sys 0.019s Metrics: {}
I20260812 06:18:08.857240 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling UndoDeltaBlockGCOp(3d27dea4bfc947e88dfeb9e5cf61b830): 447 bytes on disk
I20260812 06:18:08.857683 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: UndoDeltaBlockGCOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:18:08.858132 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=2.188937
I20260812 06:18:08.880312 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.022s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6117,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:08.880739 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=2.188937
I20260812 06:18:08.891424 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4102,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:08.891899 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=1.000000
I20260812 06:18:09.079619 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.188s	user 0.128s	sys 0.060s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877338,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":559,"lbm_read_time_us":13390,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32515,"lbm_writes_lt_1ms":643,"mutex_wait_us":83,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":14720,"thread_start_us":83,"threads_started":1,"update_count":3000}
I20260812 06:18:09.082084 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=14.095187
I20260812 06:18:09.123875 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.042s	user 0.018s	sys 0.021s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19343,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:09.124348 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=1.000000
I20260812 06:18:09.257647 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.133s	user 0.085s	sys 0.047s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":689,"lbm_read_time_us":9445,"lbm_reads_lt_1ms":467,"lbm_write_time_us":23611,"lbm_writes_lt_1ms":443,"mutex_wait_us":319,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:09.258273 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=11.118625
I20260812 06:18:09.288244 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.030s	user 0.007s	sys 0.019s Metrics: {"bytes_written":12594659,"delete_count":0,"lbm_write_time_us":13251,"lbm_writes_lt_1ms":310,"reinsert_count":0,"update_count":1535}
I20260812 06:18:09.288753 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=2.188937
I20260812 06:18:09.298677 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3815484,"delete_count":0,"lbm_write_time_us":3813,"lbm_writes_lt_1ms":96,"reinsert_count":0,"update_count":465}
I20260812 06:18:09.299227 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=1.000000
I20260812 06:18:09.432384 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.133s	user 0.112s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":974,"lbm_read_time_us":9621,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23613,"lbm_writes_lt_1ms":443,"mutex_wait_us":328,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":21504,"update_count":2000}
I20260812 06:18:09.433025 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=10.126437
I20260812 06:18:09.478914 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.046s	user 0.017s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17351,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:09.479383 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=2.188937
I20260812 06:18:09.489899 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.010s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4073,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:09.490619 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=1.000000
I20260812 06:18:09.616221 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.125s	user 0.077s	sys 0.045s 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":3266,"lbm_read_time_us":9699,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23427,"lbm_writes_lt_1ms":443,"mutex_wait_us":2923,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2000}
I20260812 06:18:09.616770 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=10.126437
I20260812 06:18:09.658521 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.042s	user 0.022s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17473,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:09.658980 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=2.188937
I20260812 06:18:09.674975 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5673,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:09.675611 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=1.000000
I20260812 06:18:09.795082 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.119s	user 0.087s	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":416,"lbm_read_time_us":9467,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22165,"lbm_writes_lt_1ms":443,"mutex_wait_us":19,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":22528,"update_count":2000}
I20260812 06:18:09.795684 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=10.126437
I20260812 06:18:09.846992 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.051s	user 0.018s	sys 0.031s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17397,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:09.847584 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=2.188937
I20260812 06:18:09.865159 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.017s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6567,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:09.865721 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=1.000000
I20260812 06:18:10.007858 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.142s	user 0.106s	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":346,"lbm_read_time_us":11212,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21650,"lbm_writes_lt_1ms":443,"mutex_wait_us":79,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7168,"update_count":2000}
I20260812 06:18:10.008739 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=10.126437
I20260812 06:18:10.053110 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.044s	user 0.024s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18056,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:10.053632 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=2.188937
I20260812 06:18:10.064512 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4056,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:10.065184 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=1.000000
I20260812 06:18:10.179363 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.114s	user 0.073s	sys 0.041s 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":907,"lbm_read_time_us":7842,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22599,"lbm_writes_lt_1ms":443,"mutex_wait_us":76,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:10.180119 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=10.126437
I20260812 06:18:10.216027 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.036s	user 0.027s	sys 0.005s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14506,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:10.216627 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=2.188937
I20260812 06:18:10.228340 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.012s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4220,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:10.228900 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushMRSOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=1.000000
I20260812 06:18:10.260576 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushMRSOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.031s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":143,"dirs.run_cpu_time_us":184,"dirs.run_wall_time_us":1339,"drs_written":1,"lbm_read_time_us":79,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2172,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:10.261335 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling LogGCOp(3d27dea4bfc947e88dfeb9e5cf61b830): free 124257255 bytes of WAL
I20260812 06:18:10.261577 11429 log_reader.cc:385] T 3d27dea4bfc947e88dfeb9e5cf61b830: removed 12 log segments from log reader
I20260812 06:18:10.261621 11429 log.cc:1079] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3d27dea4bfc947e88dfeb9e5cf61b830/wal-000000014 (ops 66-70)
I20260812 06:18:10.261650 11429 log.cc:1079] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3d27dea4bfc947e88dfeb9e5cf61b830/wal-000000015 (ops 71-75)
I20260812 06:18:10.261713 11429 log.cc:1079] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3d27dea4bfc947e88dfeb9e5cf61b830/wal-000000016 (ops 76-80)
I20260812 06:18:10.261754 11429 log.cc:1079] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3d27dea4bfc947e88dfeb9e5cf61b830/wal-000000017 (ops 81-85)
I20260812 06:18:10.261792 11429 log.cc:1079] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3d27dea4bfc947e88dfeb9e5cf61b830/wal-000000018 (ops 86-90)
I20260812 06:18:10.261829 11429 log.cc:1079] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3d27dea4bfc947e88dfeb9e5cf61b830/wal-000000019 (ops 91-95)
I20260812 06:18:10.261873 11429 log.cc:1079] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3d27dea4bfc947e88dfeb9e5cf61b830/wal-000000020 (ops 96-100)
I20260812 06:18:10.261912 11429 log.cc:1079] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3d27dea4bfc947e88dfeb9e5cf61b830/wal-000000021 (ops 101-105)
I20260812 06:18:10.261950 11429 log.cc:1079] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3d27dea4bfc947e88dfeb9e5cf61b830/wal-000000022 (ops 106-110)
I20260812 06:18:10.261988 11429 log.cc:1079] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3d27dea4bfc947e88dfeb9e5cf61b830/wal-000000023 (ops 111-114)
I20260812 06:18:10.262027 11429 log.cc:1079] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3d27dea4bfc947e88dfeb9e5cf61b830/wal-000000024 (ops 115-119)
I20260812 06:18:10.262064 11429 log.cc:1079] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3d27dea4bfc947e88dfeb9e5cf61b830/wal-000000025 (ops 120-124)
I20260812 06:18:10.289764 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: LogGCOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.028s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:18:10.290194 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling UndoDeltaBlockGCOp(3d27dea4bfc947e88dfeb9e5cf61b830): 472 bytes on disk
I20260812 06:18:10.290688 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: UndoDeltaBlockGCOp(3d27dea4bfc947e88dfeb9e5cf61b830) 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:18:10.291216 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=3.181125
I20260812 06:18:10.310096 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.019s	user 0.005s	sys 0.012s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":7840,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:10.310560 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=2.188937
I20260812 06:18:10.322695 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.012s	user 0.001s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4296,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:10.323268 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=1.000000
I20260812 06:18:10.491322 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.168s	user 0.140s	sys 0.027s 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":1021,"lbm_read_time_us":10910,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33888,"lbm_writes_lt_1ms":643,"mutex_wait_us":314,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6400,"thread_start_us":77,"threads_started":1,"update_count":3000}
I20260812 06:18:10.491874 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=14.095187
I20260812 06:18:10.549937 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.058s	user 0.025s	sys 0.031s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24465,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:10.550686 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=2.188937
I20260812 06:18:10.566622 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.016s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4976,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:10.567215 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=1.000000
I20260812 06:18:10.724375 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.157s	user 0.104s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":764,"lbm_read_time_us":8970,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30699,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:10.725056 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=14.095187
I20260812 06:18:10.777124 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.052s	user 0.034s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20290,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:10.777709 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=1.000000
I20260812 06:18:10.937825 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.160s	user 0.128s	sys 0.020s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":207,"lbm_read_time_us":10625,"lbm_reads_lt_1ms":463,"lbm_write_time_us":24841,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2000}
I20260812 06:18:10.938493 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=14.095187
I20260812 06:18:10.990286 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.052s	user 0.018s	sys 0.028s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21237,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:10.990810 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=2.188937
I20260812 06:18:11.002791 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4141,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.003422 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=1.000000
I20260812 06:18:11.200618 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.197s	user 0.127s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":371,"lbm_read_time_us":13006,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29127,"lbm_writes_lt_1ms":543,"mutex_wait_us":77,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11904,"update_count":2500}
I20260812 06:18:11.201349 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=14.095187
I20260812 06:18:11.259513 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.058s	user 0.031s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":28674,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:18:11.260062 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=2.188937
I20260812 06:18:11.274560 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.014s	user 0.004s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4906,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.275274 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=1.000000
I20260812 06:18:11.439556 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.164s	user 0.105s	sys 0.055s 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":708,"lbm_read_time_us":9464,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32623,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9216,"update_count":2500}
I20260812 06:18:11.440182 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=14.095187
I20260812 06:18:11.491230 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.051s	user 0.028s	sys 0.013s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":19478,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:11.491813 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=2.188937
I20260812 06:18:11.503938 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.012s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4214,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.504515 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=1.000000
I20260812 06:18:11.656769 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.152s	user 0.098s	sys 0.053s 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":1153,"lbm_read_time_us":10534,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31188,"lbm_writes_lt_1ms":543,"mutex_wait_us":382,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:18:11.657437 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=14.095187
I20260812 06:18:11.705906 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.048s	user 0.017s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19017,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:11.706478 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=2.188937
I20260812 06:18:11.717941 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.011s	user 0.001s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4304,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.718425 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushMRSOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=1.000000
I20260812 06:18:11.745707 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushMRSOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.027s	user 0.025s	sys 0.001s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":203,"dirs.run_wall_time_us":1542,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1616,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:11.746517 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling LogGCOp(3d27dea4bfc947e88dfeb9e5cf61b830): free 129773817 bytes of WAL
I20260812 06:18:11.746774 11429 log_reader.cc:385] T 3d27dea4bfc947e88dfeb9e5cf61b830: removed 13 log segments from log reader
I20260812 06:18:11.746845 11429 log.cc:1079] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3d27dea4bfc947e88dfeb9e5cf61b830/wal-000000026 (ops 125-129)
I20260812 06:18:11.746901 11429 log.cc:1079] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3d27dea4bfc947e88dfeb9e5cf61b830/wal-000000027 (ops 130-134)
I20260812 06:18:11.746963 11429 log.cc:1079] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3d27dea4bfc947e88dfeb9e5cf61b830/wal-000000028 (ops 135-139)
I20260812 06:18:11.747005 11429 log.cc:1079] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3d27dea4bfc947e88dfeb9e5cf61b830/wal-000000029 (ops 140-144)
I20260812 06:18:11.747042 11429 log.cc:1079] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3d27dea4bfc947e88dfeb9e5cf61b830/wal-000000030 (ops 145-149)
I20260812 06:18:11.747083 11429 log.cc:1079] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3d27dea4bfc947e88dfeb9e5cf61b830/wal-000000031 (ops 150-154)
I20260812 06:18:11.747123 11429 log.cc:1079] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3d27dea4bfc947e88dfeb9e5cf61b830/wal-000000032 (ops 155-159)
I20260812 06:18:11.747162 11429 log.cc:1079] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3d27dea4bfc947e88dfeb9e5cf61b830/wal-000000033 (ops 160-164)
I20260812 06:18:11.747201 11429 log.cc:1079] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3d27dea4bfc947e88dfeb9e5cf61b830/wal-000000034 (ops 165-168)
I20260812 06:18:11.747241 11429 log.cc:1079] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3d27dea4bfc947e88dfeb9e5cf61b830/wal-000000035 (ops 169-173)
I20260812 06:18:11.747279 11429 log.cc:1079] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3d27dea4bfc947e88dfeb9e5cf61b830/wal-000000036 (ops 174-178)
I20260812 06:18:11.747318 11429 log.cc:1079] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3d27dea4bfc947e88dfeb9e5cf61b830/wal-000000037 (ops 179-183)
I20260812 06:18:11.747357 11429 log.cc:1079] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3d27dea4bfc947e88dfeb9e5cf61b830/wal-000000038 (ops 184-188)
I20260812 06:18:11.778172 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: LogGCOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.031s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:18:11.778637 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling UndoDeltaBlockGCOp(3d27dea4bfc947e88dfeb9e5cf61b830): 482 bytes on disk
I20260812 06:18:11.779325 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: UndoDeltaBlockGCOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4}
I20260812 06:18:11.779934 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=3.181125
I20260812 06:18:11.795614 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":5251342,"delete_count":0,"lbm_write_time_us":6295,"lbm_writes_lt_1ms":131,"reinsert_count":0,"update_count":640}
I20260812 06:18:11.796139 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=1.196750
I20260812 06:18:11.808508 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":2953955,"delete_count":0,"lbm_write_time_us":4309,"lbm_writes_lt_1ms":75,"reinsert_count":0,"update_count":360}
I20260812 06:18:11.809346 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=1.000000
I20260812 06:18:12.053208 11230 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.729s	user 1.780s	sys 0.123s
I20260812 06:18:12.055393 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: MajorDeltaCompactionOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.246s	user 0.169s	sys 0.060s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":344,"lbm_read_time_us":15190,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39456,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":13952,"thread_start_us":121,"threads_started":1,"update_count":3500}
I20260812 06:18:12.055938 11543 maintenance_manager.cc:419] P ead6084830f946a8ab46d990b9e18f1c: Scheduling FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830): perf score=18.063937
I20260812 06:18:12.098289 11230 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.044s	user 0.003s	sys 0.000s
I20260812 06:18:12.099046 11230 tablet_server.cc:179] TabletServer@127.10.247.129:0 shutting down...
I20260812 06:18:12.128587 11429 maintenance_manager.cc:643] P ead6084830f946a8ab46d990b9e18f1c: FlushDeltaMemStoresOp(3d27dea4bfc947e88dfeb9e5cf61b830) complete. Timing: real 0.072s	user 0.036s	sys 0.032s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":28385,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:12.129285 11230 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:12.129757 11230 tablet_replica.cc:333] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c: stopping tablet replica
I20260812 06:18:12.129959 11230 raft_consensus.cc:2243] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:12.130155 11230 raft_consensus.cc:2272] T 3d27dea4bfc947e88dfeb9e5cf61b830 P ead6084830f946a8ab46d990b9e18f1c [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:12.144712 11230 tablet_server.cc:196] TabletServer@127.10.247.129:0 shutdown complete.
I20260812 06:18:12.149358 11230 master.cc:562] Master@127.10.247.190:37829 shutting down...
I20260812 06:18:12.153329 11230 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 048a8cc92dac4592a49fe2d4f13a8dce [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:12.153498 11230 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 048a8cc92dac4592a49fe2d4f13a8dce [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:12.153595 11230 tablet_replica.cc:333] T 00000000000000000000000000000000 P 048a8cc92dac4592a49fe2d4f13a8dce: stopping tablet replica
I20260812 06:18:12.165732 11230 master.cc:584] Master@127.10.247.190:37829 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5245 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:12.260191 11230 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.10.247.190:39719
I20260812 06:18:12.260628 11230 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:12.262802 11607 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:12.262892 11603 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:12.262907 11600 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:12.263034 11230 server_base.cc:1061] running on GCE node
I20260812 06:18:12.263237 11230 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:12.263298 11230 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:12.263324 11230 hybrid_clock.cc:648] HybridClock initialized: now 1786515492263322 us; error 0 us; skew 500 ppm
I20260812 06:18:12.264159 11230 webserver.cc:533] Webserver started at http://127.10.247.190:45793/ using document root <none> and password file <none>
I20260812 06:18:12.264338 11230 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:12.264405 11230 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:12.264504 11230 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:12.264997 11230 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/master-0-root/instance:
uuid: "ca18c1c09ef749429c27aeee3b1a4e9d"
format_stamp: "Formatted at 2026-08-12 06:18:12 on dist-test-slave-2kcd"
I20260812 06:18:12.266469 11230 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:12.267365 11620 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:12.267638 11230 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:12.267735 11230 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/master-0-root
uuid: "ca18c1c09ef749429c27aeee3b1a4e9d"
format_stamp: "Formatted at 2026-08-12 06:18:12 on dist-test-slave-2kcd"
I20260812 06:18:12.267817 11230 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:12.283200 11230 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:12.283574 11230 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:12.287726 11230 rpc_server.cc:307] RPC server started. Bound to: 127.10.247.190:39719
I20260812 06:18:12.298381 11708 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.247.190:39719 every 8 connection(s)
I20260812 06:18:12.298879 11711 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:12.300661 11711 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ca18c1c09ef749429c27aeee3b1a4e9d: Bootstrap starting.
I20260812 06:18:12.301467 11711 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P ca18c1c09ef749429c27aeee3b1a4e9d: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:12.302475 11711 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P ca18c1c09ef749429c27aeee3b1a4e9d: No bootstrap required, opened a new log
I20260812 06:18:12.302889 11711 raft_consensus.cc:359] T 00000000000000000000000000000000 P ca18c1c09ef749429c27aeee3b1a4e9d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ca18c1c09ef749429c27aeee3b1a4e9d" member_type: VOTER }
I20260812 06:18:12.302976 11711 raft_consensus.cc:385] T 00000000000000000000000000000000 P ca18c1c09ef749429c27aeee3b1a4e9d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:12.303035 11711 raft_consensus.cc:740] T 00000000000000000000000000000000 P ca18c1c09ef749429c27aeee3b1a4e9d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ca18c1c09ef749429c27aeee3b1a4e9d, State: Initialized, Role: FOLLOWER
I20260812 06:18:12.303229 11711 consensus_queue.cc:260] T 00000000000000000000000000000000 P ca18c1c09ef749429c27aeee3b1a4e9d [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: "ca18c1c09ef749429c27aeee3b1a4e9d" member_type: VOTER }
I20260812 06:18:12.303328 11711 raft_consensus.cc:399] T 00000000000000000000000000000000 P ca18c1c09ef749429c27aeee3b1a4e9d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:12.303396 11711 raft_consensus.cc:493] T 00000000000000000000000000000000 P ca18c1c09ef749429c27aeee3b1a4e9d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:12.303458 11711 raft_consensus.cc:3060] T 00000000000000000000000000000000 P ca18c1c09ef749429c27aeee3b1a4e9d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:12.304140 11711 raft_consensus.cc:515] T 00000000000000000000000000000000 P ca18c1c09ef749429c27aeee3b1a4e9d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ca18c1c09ef749429c27aeee3b1a4e9d" member_type: VOTER }
I20260812 06:18:12.304298 11711 leader_election.cc:304] T 00000000000000000000000000000000 P ca18c1c09ef749429c27aeee3b1a4e9d [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: ca18c1c09ef749429c27aeee3b1a4e9d; no voters: 
I20260812 06:18:12.304512 11711 leader_election.cc:290] T 00000000000000000000000000000000 P ca18c1c09ef749429c27aeee3b1a4e9d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:12.304646 11718 raft_consensus.cc:2804] T 00000000000000000000000000000000 P ca18c1c09ef749429c27aeee3b1a4e9d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:12.304879 11718 raft_consensus.cc:697] T 00000000000000000000000000000000 P ca18c1c09ef749429c27aeee3b1a4e9d [term 1 LEADER]: Becoming Leader. State: Replica: ca18c1c09ef749429c27aeee3b1a4e9d, State: Running, Role: LEADER
I20260812 06:18:12.305018 11718 consensus_queue.cc:237] T 00000000000000000000000000000000 P ca18c1c09ef749429c27aeee3b1a4e9d [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: "ca18c1c09ef749429c27aeee3b1a4e9d" member_type: VOTER }
I20260812 06:18:12.305063 11711 sys_catalog.cc:565] T 00000000000000000000000000000000 P ca18c1c09ef749429c27aeee3b1a4e9d [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:12.305490 11723 sys_catalog.cc:455] T 00000000000000000000000000000000 P ca18c1c09ef749429c27aeee3b1a4e9d [sys.catalog]: SysCatalogTable state changed. Reason: New leader ca18c1c09ef749429c27aeee3b1a4e9d. Latest consensus state: current_term: 1 leader_uuid: "ca18c1c09ef749429c27aeee3b1a4e9d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ca18c1c09ef749429c27aeee3b1a4e9d" member_type: VOTER } }
I20260812 06:18:12.305461 11720 sys_catalog.cc:455] T 00000000000000000000000000000000 P ca18c1c09ef749429c27aeee3b1a4e9d [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "ca18c1c09ef749429c27aeee3b1a4e9d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ca18c1c09ef749429c27aeee3b1a4e9d" member_type: VOTER } }
I20260812 06:18:12.305612 11723 sys_catalog.cc:458] T 00000000000000000000000000000000 P ca18c1c09ef749429c27aeee3b1a4e9d [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:12.305676 11720 sys_catalog.cc:458] T 00000000000000000000000000000000 P ca18c1c09ef749429c27aeee3b1a4e9d [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:12.306260 11728 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:12.307163 11728 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:12.307425 11230 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:12.309082 11728 catalog_manager.cc:1383] Generated new cluster ID: 6844d55d198745fc99ad399a02450077
I20260812 06:18:12.309129 11728 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:12.339170 11728 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:12.339720 11728 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:12.344936 11728 catalog_manager.cc:6092] T 00000000000000000000000000000000 P ca18c1c09ef749429c27aeee3b1a4e9d: Generated new TSK 0
I20260812 06:18:12.345091 11728 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:12.372025 11230 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:12.374060 11753 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:12.374182 11230 server_base.cc:1061] running on GCE node
W20260812 06:18:12.374183 11758 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:12.374220 11752 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:12.374523 11230 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:12.374593 11230 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:12.374626 11230 hybrid_clock.cc:648] HybridClock initialized: now 1786515492374625 us; error 0 us; skew 500 ppm
I20260812 06:18:12.375478 11230 webserver.cc:533] Webserver started at http://127.10.247.129:39387/ using document root <none> and password file <none>
I20260812 06:18:12.375660 11230 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:12.375731 11230 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:12.375808 11230 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:12.376226 11230 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/instance:
uuid: "52bbf1a4f93a4dcc969f43e9264e3bd7"
format_stamp: "Formatted at 2026-08-12 06:18:12 on dist-test-slave-2kcd"
I20260812 06:18:12.377817 11230 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.001s
I20260812 06:18:12.378755 11768 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:12.379012 11230 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:12.379102 11230 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root
uuid: "52bbf1a4f93a4dcc969f43e9264e3bd7"
format_stamp: "Formatted at 2026-08-12 06:18:12 on dist-test-slave-2kcd"
I20260812 06:18:12.379184 11230 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:12.391031 11230 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:12.391500 11230 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:12.391808 11230 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:12.392289 11230 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:12.392352 11230 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:12.392412 11230 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:12.392454 11230 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:12.396612 11230 rpc_server.cc:307] RPC server started. Bound to: 127.10.247.129:46615
I20260812 06:18:12.396647 11890 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.247.129:46615 every 8 connection(s)
I20260812 06:18:12.405272 11892 heartbeater.cc:344] Connected to a master server at 127.10.247.190:39719
I20260812 06:18:12.405393 11892 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:12.405658 11892 heartbeater.cc:507] Master 127.10.247.190:39719 requested a full tablet report, sending...
I20260812 06:18:12.406395 11649 ts_manager.cc:194] Registered new tserver with Master: 52bbf1a4f93a4dcc969f43e9264e3bd7 (127.10.247.129:46615)
I20260812 06:18:12.407063 11230 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.009917286s
I20260812 06:18:12.407176 11649 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:47160
I20260812 06:18:12.414003 11649 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:47164:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:12.422741 11814 tablet_service.cc:1511] Processing CreateTablet for tablet 3108d7dbf4ed4983aa05f84fa26375cb (DEFAULT_TABLE table=heavy-update-compaction-test [id=74317876f81847a4b89040228eb508c0]), partition=
I20260812 06:18:12.423045 11814 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 3108d7dbf4ed4983aa05f84fa26375cb. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:12.425092 11907 tablet_bootstrap.cc:492] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Bootstrap starting.
I20260812 06:18:12.426009 11907 tablet_bootstrap.cc:654] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:12.427073 11907 tablet_bootstrap.cc:492] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: No bootstrap required, opened a new log
I20260812 06:18:12.427145 11907 ts_tablet_manager.cc:1403] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:18:12.427521 11907 raft_consensus.cc:359] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "52bbf1a4f93a4dcc969f43e9264e3bd7" member_type: VOTER last_known_addr { host: "127.10.247.129" port: 46615 } }
I20260812 06:18:12.427605 11907 raft_consensus.cc:385] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:12.427627 11907 raft_consensus.cc:740] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 52bbf1a4f93a4dcc969f43e9264e3bd7, State: Initialized, Role: FOLLOWER
I20260812 06:18:12.427727 11907 consensus_queue.cc:260] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7 [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: "52bbf1a4f93a4dcc969f43e9264e3bd7" member_type: VOTER last_known_addr { host: "127.10.247.129" port: 46615 } }
I20260812 06:18:12.427786 11907 raft_consensus.cc:399] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:12.427809 11907 raft_consensus.cc:493] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:12.427865 11907 raft_consensus.cc:3060] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:12.428841 11907 raft_consensus.cc:515] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "52bbf1a4f93a4dcc969f43e9264e3bd7" member_type: VOTER last_known_addr { host: "127.10.247.129" port: 46615 } }
I20260812 06:18:12.428974 11907 leader_election.cc:304] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7 [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: 52bbf1a4f93a4dcc969f43e9264e3bd7; no voters: 
I20260812 06:18:12.429162 11907 leader_election.cc:290] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:12.429293 11911 raft_consensus.cc:2804] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:12.429504 11907 ts_tablet_manager.cc:1434] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:18:12.429563 11911 raft_consensus.cc:697] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7 [term 1 LEADER]: Becoming Leader. State: Replica: 52bbf1a4f93a4dcc969f43e9264e3bd7, State: Running, Role: LEADER
I20260812 06:18:12.429546 11892 heartbeater.cc:499] Master 127.10.247.190:39719 was elected leader, sending a full tablet report...
I20260812 06:18:12.429726 11911 consensus_queue.cc:237] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7 [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: "52bbf1a4f93a4dcc969f43e9264e3bd7" member_type: VOTER last_known_addr { host: "127.10.247.129" port: 46615 } }
I20260812 06:18:12.431149 11649 catalog_manager.cc:5719] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7 reported cstate change: term changed from 0 to 1, leader changed from <none> to 52bbf1a4f93a4dcc969f43e9264e3bd7 (127.10.247.129). New cstate: current_term: 1 leader_uuid: "52bbf1a4f93a4dcc969f43e9264e3bd7" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "52bbf1a4f93a4dcc969f43e9264e3bd7" member_type: VOTER last_known_addr { host: "127.10.247.129" port: 46615 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:12.491776 11230 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.020s	sys 0.003s
I20260812 06:18:12.647557 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushMRSOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=19.054940
I20260812 06:18:12.805840 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushMRSOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.158s	user 0.101s	sys 0.056s Metrics: {"bytes_written":12881831,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":217,"dirs.run_wall_time_us":908,"drs_written":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39510,"lbm_writes_lt_1ms":771,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1570}
I20260812 06:18:12.806744 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling LogGCOp(3108d7dbf4ed4983aa05f84fa26375cb): free 20743880 bytes of WAL
I20260812 06:18:12.807087 11778 log_reader.cc:385] T 3108d7dbf4ed4983aa05f84fa26375cb: removed 2 log segments from log reader
I20260812 06:18:12.807173 11778 log.cc:1079] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3108d7dbf4ed4983aa05f84fa26375cb/wal-000000001 (ops 1-6)
I20260812 06:18:12.807216 11778 log.cc:1079] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3108d7dbf4ed4983aa05f84fa26375cb/wal-000000002 (ops 7-11)
I20260812 06:18:12.812983 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: LogGCOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.006s	user 0.000s	sys 0.006s Metrics: {}
I20260812 06:18:12.813277 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=2.188937
I20260812 06:18:12.827013 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.014s	user 0.000s	sys 0.008s Metrics: {"bytes_written":3938560,"delete_count":0,"lbm_write_time_us":3849,"lbm_writes_lt_1ms":99,"reinsert_count":0,"update_count":480}
I20260812 06:18:12.827454 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling UndoDeltaBlockGCOp(3108d7dbf4ed4983aa05f84fa26375cb): 16411395 bytes on disk
I20260812 06:18:12.827863 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: UndoDeltaBlockGCOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:18:12.828245 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=2.188937
I20260812 06:18:12.837888 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3640,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:12.838301 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling MajorDeltaCompactionOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=1.000000
I20260812 06:18:13.022003 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: MajorDeltaCompactionOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.184s	user 0.137s	sys 0.043s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774796,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":567,"lbm_read_time_us":12901,"lbm_reads_lt_1ms":569,"lbm_write_time_us":29571,"lbm_writes_lt_1ms":543,"mutex_wait_us":79,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6656,"thread_start_us":344,"threads_started":5,"update_count":2500}
I20260812 06:18:13.022620 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=14.095187
I20260812 06:18:13.085603 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.063s	user 0.027s	sys 0.024s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":23550,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:13.086030 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=2.188937
I20260812 06:18:13.096127 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3956,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.096598 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling MajorDeltaCompactionOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=1.000000
I20260812 06:18:13.273561 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: MajorDeltaCompactionOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.177s	user 0.109s	sys 0.067s 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":196,"lbm_read_time_us":14514,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28539,"lbm_writes_lt_1ms":543,"mutex_wait_us":31,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2500}
I20260812 06:18:13.274195 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=14.095187
I20260812 06:18:13.336426 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.062s	user 0.036s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26362,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:13.337229 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=2.188937
I20260812 06:18:13.353932 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.016s	user 0.014s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6092,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.354386 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling MajorDeltaCompactionOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=1.000000
I20260812 06:18:13.534363 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: MajorDeltaCompactionOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.180s	user 0.142s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":363,"lbm_read_time_us":13190,"lbm_reads_lt_1ms":568,"lbm_write_time_us":30255,"lbm_writes_lt_1ms":543,"mutex_wait_us":1,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2500}
I20260812 06:18:13.534967 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=14.095187
I20260812 06:18:13.590408 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.055s	user 0.033s	sys 0.020s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":19619,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:13.590911 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=2.188937
I20260812 06:18:13.601473 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4119,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.601864 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling MajorDeltaCompactionOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=1.000000
I20260812 06:18:13.784209 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: MajorDeltaCompactionOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.182s	user 0.110s	sys 0.072s 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":994,"lbm_read_time_us":13505,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29528,"lbm_writes_lt_1ms":543,"mutex_wait_us":270,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":2500}
I20260812 06:18:13.784819 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=14.095187
I20260812 06:18:13.842464 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.057s	user 0.024s	sys 0.025s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23003,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:13.842931 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=2.188937
I20260812 06:18:13.864985 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.022s	user 0.006s	sys 0.015s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4040,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.865613 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling MajorDeltaCompactionOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=1.000000
I20260812 06:18:14.055236 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: MajorDeltaCompactionOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.189s	user 0.128s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":236,"lbm_read_time_us":13243,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29350,"lbm_writes_lt_1ms":543,"mutex_wait_us":76,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":2500}
I20260812 06:18:14.055749 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=14.095187
I20260812 06:18:14.128719 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.073s	user 0.042s	sys 0.004s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21025,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:14.129483 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=2.188937
I20260812 06:18:14.143394 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.014s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4980,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.143987 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushMRSOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=1.000000
I20260812 06:18:14.187071 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushMRSOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.043s	user 0.038s	sys 0.003s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":37,"dirs.run_cpu_time_us":184,"dirs.run_wall_time_us":1527,"drs_written":1,"lbm_read_time_us":100,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2241,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:14.187790 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling LogGCOp(3108d7dbf4ed4983aa05f84fa26375cb): free 124257253 bytes of WAL
I20260812 06:18:14.188014 11778 log_reader.cc:385] T 3108d7dbf4ed4983aa05f84fa26375cb: removed 12 log segments from log reader
I20260812 06:18:14.188076 11778 log.cc:1079] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3108d7dbf4ed4983aa05f84fa26375cb/wal-000000003 (ops 12-16)
I20260812 06:18:14.188165 11778 log.cc:1079] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3108d7dbf4ed4983aa05f84fa26375cb/wal-000000004 (ops 17-21)
I20260812 06:18:14.188206 11778 log.cc:1079] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3108d7dbf4ed4983aa05f84fa26375cb/wal-000000005 (ops 22-26)
I20260812 06:18:14.188251 11778 log.cc:1079] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3108d7dbf4ed4983aa05f84fa26375cb/wal-000000006 (ops 27-31)
I20260812 06:18:14.188293 11778 log.cc:1079] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3108d7dbf4ed4983aa05f84fa26375cb/wal-000000007 (ops 32-36)
I20260812 06:18:14.188333 11778 log.cc:1079] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3108d7dbf4ed4983aa05f84fa26375cb/wal-000000008 (ops 37-41)
I20260812 06:18:14.188401 11778 log.cc:1079] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3108d7dbf4ed4983aa05f84fa26375cb/wal-000000009 (ops 42-46)
I20260812 06:18:14.188441 11778 log.cc:1079] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3108d7dbf4ed4983aa05f84fa26375cb/wal-000000010 (ops 47-51)
I20260812 06:18:14.188519 11778 log.cc:1079] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3108d7dbf4ed4983aa05f84fa26375cb/wal-000000011 (ops 52-56)
I20260812 06:18:14.188575 11778 log.cc:1079] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3108d7dbf4ed4983aa05f84fa26375cb/wal-000000012 (ops 57-61)
I20260812 06:18:14.188618 11778 log.cc:1079] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3108d7dbf4ed4983aa05f84fa26375cb/wal-000000013 (ops 62-66)
I20260812 06:18:14.188661 11778 log.cc:1079] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3108d7dbf4ed4983aa05f84fa26375cb/wal-000000014 (ops 67-70)
I20260812 06:18:14.218991 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: LogGCOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.031s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:18:14.220697 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling UndoDeltaBlockGCOp(3108d7dbf4ed4983aa05f84fa26375cb): 472 bytes on disk
I20260812 06:18:14.223199 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: UndoDeltaBlockGCOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":104,"lbm_reads_lt_1ms":4}
I20260812 06:18:14.223883 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=3.181125
I20260812 06:18:14.244833 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.021s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":5775,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:14.245343 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=2.188937
I20260812 06:18:14.259929 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.014s	user 0.009s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5400,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:14.260601 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling MajorDeltaCompactionOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=1.000000
I20260812 06:18:14.523695 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: MajorDeltaCompactionOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.263s	user 0.173s	sys 0.084s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979741,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1399,"lbm_read_time_us":18620,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39286,"lbm_writes_lt_1ms":743,"mutex_wait_us":268,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2688,"thread_start_us":97,"threads_started":1,"update_count":3500}
I20260812 06:18:14.524593 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=18.063937
I20260812 06:18:14.594645 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.070s	user 0.024s	sys 0.035s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":28266,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:14.595254 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=2.188937
I20260812 06:18:14.605805 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4039,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.606519 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling MajorDeltaCompactionOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=1.000000
I20260812 06:18:14.819468 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: MajorDeltaCompactionOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.213s	user 0.139s	sys 0.071s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":145,"lbm_read_time_us":15379,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33932,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12672,"update_count":3000}
I20260812 06:18:14.820137 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=14.095187
I20260812 06:18:14.863431 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.043s	user 0.029s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18469,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:14.864027 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=2.188937
I20260812 06:18:14.892077 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.028s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6425,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.892632 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=2.188937
I20260812 06:18:14.902736 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3941,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.903173 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling MajorDeltaCompactionOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=1.000000
I20260812 06:18:15.119313 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: MajorDeltaCompactionOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.216s	user 0.138s	sys 0.061s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877219,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":125,"lbm_read_time_us":13944,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32875,"lbm_writes_lt_1ms":643,"mutex_wait_us":19,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":24320,"update_count":3000}
I20260812 06:18:15.123349 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=18.063937
I20260812 06:18:15.184296 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.061s	user 0.036s	sys 0.021s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":27428,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:15.184870 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=2.188937
I20260812 06:18:15.196338 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4171,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.196874 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling MajorDeltaCompactionOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=1.000000
I20260812 06:18:15.406185 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: MajorDeltaCompactionOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.209s	user 0.124s	sys 0.081s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877101,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":673,"lbm_read_time_us":16203,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35935,"lbm_writes_lt_1ms":643,"mutex_wait_us":241,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":3000}
I20260812 06:18:15.406958 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=15.087375
I20260812 06:18:15.463949 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.057s	user 0.035s	sys 0.015s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":23816,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:18:15.464462 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=2.188937
I20260812 06:18:15.475369 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4201,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.475824 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=2.188937
I20260812 06:18:15.485494 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.009s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3745,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:15.485925 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling MajorDeltaCompactionOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=1.000000
I20260812 06:18:15.657634 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: MajorDeltaCompactionOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.172s	user 0.139s	sys 0.031s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877207,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":230,"lbm_read_time_us":14507,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35553,"lbm_writes_lt_1ms":643,"mutex_wait_us":21,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":22528,"update_count":3000}
I20260812 06:18:15.658392 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=14.095187
I20260812 06:18:15.706224 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.048s	user 0.023s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19409,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:15.706763 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=2.188937
I20260812 06:18:15.721910 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5778,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.722575 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushMRSOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=1.000000
I20260812 06:18:15.757303 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushMRSOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.035s	user 0.030s	sys 0.004s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":178,"dirs.run_wall_time_us":1499,"drs_written":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2174,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:15.758021 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling LogGCOp(3108d7dbf4ed4983aa05f84fa26375cb): free 121006384 bytes of WAL
I20260812 06:18:15.758289 11778 log_reader.cc:385] T 3108d7dbf4ed4983aa05f84fa26375cb: removed 12 log segments from log reader
I20260812 06:18:15.758350 11778 log.cc:1079] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3108d7dbf4ed4983aa05f84fa26375cb/wal-000000015 (ops 71-75)
I20260812 06:18:15.758391 11778 log.cc:1079] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3108d7dbf4ed4983aa05f84fa26375cb/wal-000000016 (ops 76-80)
I20260812 06:18:15.758425 11778 log.cc:1079] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3108d7dbf4ed4983aa05f84fa26375cb/wal-000000017 (ops 81-85)
I20260812 06:18:15.758450 11778 log.cc:1079] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3108d7dbf4ed4983aa05f84fa26375cb/wal-000000018 (ops 86-90)
I20260812 06:18:15.758471 11778 log.cc:1079] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3108d7dbf4ed4983aa05f84fa26375cb/wal-000000019 (ops 91-95)
I20260812 06:18:15.758500 11778 log.cc:1079] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3108d7dbf4ed4983aa05f84fa26375cb/wal-000000020 (ops 96-100)
I20260812 06:18:15.758530 11778 log.cc:1079] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3108d7dbf4ed4983aa05f84fa26375cb/wal-000000021 (ops 101-105)
I20260812 06:18:15.758575 11778 log.cc:1079] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3108d7dbf4ed4983aa05f84fa26375cb/wal-000000022 (ops 106-110)
I20260812 06:18:15.758599 11778 log.cc:1079] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3108d7dbf4ed4983aa05f84fa26375cb/wal-000000023 (ops 111-115)
I20260812 06:18:15.758621 11778 log.cc:1079] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3108d7dbf4ed4983aa05f84fa26375cb/wal-000000024 (ops 116-120)
I20260812 06:18:15.758651 11778 log.cc:1079] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3108d7dbf4ed4983aa05f84fa26375cb/wal-000000025 (ops 121-124)
I20260812 06:18:15.758677 11778 log.cc:1079] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3108d7dbf4ed4983aa05f84fa26375cb/wal-000000026 (ops 125-129)
I20260812 06:18:15.788962 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: LogGCOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.031s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:18:15.789353 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=2.188937
I20260812 06:18:15.804556 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.015s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4350,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.805059 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling UndoDeltaBlockGCOp(3108d7dbf4ed4983aa05f84fa26375cb): 483 bytes on disk
I20260812 06:18:15.805437 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: UndoDeltaBlockGCOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:18:15.805974 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=2.188937
I20260812 06:18:15.816817 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4273,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.817476 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling MajorDeltaCompactionOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=1.000000
I20260812 06:18:16.011193 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: MajorDeltaCompactionOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.193s	user 0.138s	sys 0.052s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979751,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":512,"lbm_read_time_us":14213,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39063,"lbm_writes_lt_1ms":743,"mutex_wait_us":86,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":4096,"thread_start_us":75,"threads_started":1,"update_count":3500}
I20260812 06:18:16.011965 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=15.087375
I20260812 06:18:16.076051 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.064s	user 0.029s	sys 0.020s Metrics: {"bytes_written":16820138,"delete_count":0,"lbm_write_time_us":22866,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:18:16.076550 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=6.157687
I20260812 06:18:16.100975 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.024s	user 0.009s	sys 0.011s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":8802,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:18:16.101536 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling MajorDeltaCompactionOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=1.000000
I20260812 06:18:16.285506 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: MajorDeltaCompactionOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.184s	user 0.132s	sys 0.044s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877096,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1687,"dirs.run_cpu_time_us":2774,"dirs.run_wall_time_us":30779,"lbm_read_time_us":12506,"lbm_reads_lt_1ms":664,"lbm_write_time_us":33682,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":3000}
I20260812 06:18:16.286149 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=14.095187
I20260812 06:18:16.335161 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.047s	user 0.029s	sys 0.016s Metrics: {"bytes_written":16820144,"delete_count":0,"lbm_write_time_us":21400,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:18:16.335737 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=2.188937
I20260812 06:18:16.351949 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.016s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5690,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:16.352540 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling MajorDeltaCompactionOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=1.000000
I20260812 06:18:16.502592 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: MajorDeltaCompactionOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.150s	user 0.102s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774677,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":245,"lbm_read_time_us":9001,"lbm_reads_lt_1ms":564,"lbm_write_time_us":26753,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":86656,"update_count":2500}
I20260812 06:18:16.503444 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=14.095187
I20260812 06:18:16.563539 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.060s	user 0.022s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20134,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:16.564165 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=2.188937
I20260812 06:18:16.576012 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4270,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.576531 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling MajorDeltaCompactionOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=1.000000
I20260812 06:18:16.751883 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: MajorDeltaCompactionOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.175s	user 0.111s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":562,"lbm_read_time_us":12712,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30925,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9728,"update_count":2500}
I20260812 06:18:16.752581 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=14.095187
I20260812 06:18:16.805003 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.052s	user 0.036s	sys 0.008s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18876,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:16.805513 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=2.188937
I20260812 06:18:16.818588 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4588,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.819242 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling MajorDeltaCompactionOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=1.000000
I20260812 06:18:17.003082 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: MajorDeltaCompactionOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.184s	user 0.123s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":659,"lbm_read_time_us":13345,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30425,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":43776,"update_count":2500}
I20260812 06:18:17.003705 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=14.095187
I20260812 06:18:17.064102 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.060s	user 0.034s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23043,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:17.064685 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=2.188937
I20260812 06:18:17.075454 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4216,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.075928 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushMRSOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=1.000000
I20260812 06:18:17.118726 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushMRSOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.043s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":147,"dirs.run_wall_time_us":1258,"drs_written":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1836,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:17.119433 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling LogGCOp(3108d7dbf4ed4983aa05f84fa26375cb): free 120553638 bytes of WAL
I20260812 06:18:17.119665 11778 log_reader.cc:385] T 3108d7dbf4ed4983aa05f84fa26375cb: removed 12 log segments from log reader
I20260812 06:18:17.119714 11778 log.cc:1079] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3108d7dbf4ed4983aa05f84fa26375cb/wal-000000027 (ops 130-134)
I20260812 06:18:17.119742 11778 log.cc:1079] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3108d7dbf4ed4983aa05f84fa26375cb/wal-000000028 (ops 135-138)
I20260812 06:18:17.119799 11778 log.cc:1079] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3108d7dbf4ed4983aa05f84fa26375cb/wal-000000029 (ops 139-143)
I20260812 06:18:17.119843 11778 log.cc:1079] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3108d7dbf4ed4983aa05f84fa26375cb/wal-000000030 (ops 144-148)
I20260812 06:18:17.119897 11778 log.cc:1079] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3108d7dbf4ed4983aa05f84fa26375cb/wal-000000031 (ops 149-153)
I20260812 06:18:17.119917 11778 log.cc:1079] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3108d7dbf4ed4983aa05f84fa26375cb/wal-000000032 (ops 154-158)
I20260812 06:18:17.119975 11778 log.cc:1079] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3108d7dbf4ed4983aa05f84fa26375cb/wal-000000033 (ops 159-163)
I20260812 06:18:17.120018 11778 log.cc:1079] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3108d7dbf4ed4983aa05f84fa26375cb/wal-000000034 (ops 164-168)
I20260812 06:18:17.120057 11778 log.cc:1079] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3108d7dbf4ed4983aa05f84fa26375cb/wal-000000035 (ops 169-172)
I20260812 06:18:17.120097 11778 log.cc:1079] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3108d7dbf4ed4983aa05f84fa26375cb/wal-000000036 (ops 173-177)
I20260812 06:18:17.120136 11778 log.cc:1079] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3108d7dbf4ed4983aa05f84fa26375cb/wal-000000037 (ops 178-182)
I20260812 06:18:17.120177 11778 log.cc:1079] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: Deleting log segment in path: /tmp/dist-test-taskJ0lO5Y/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515487004645-11230-0/minicluster-data/ts-0-root/wals/3108d7dbf4ed4983aa05f84fa26375cb/wal-000000038 (ops 183-187)
I20260812 06:18:17.147563 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: LogGCOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:18:17.147966 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling UndoDeltaBlockGCOp(3108d7dbf4ed4983aa05f84fa26375cb): 447 bytes on disk
I20260812 06:18:17.148409 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: UndoDeltaBlockGCOp(3108d7dbf4ed4983aa05f84fa26375cb) 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:18:17.149044 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=2.188937
I20260812 06:18:17.171003 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.022s	user 0.009s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6341,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.171474 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=2.188937
I20260812 06:18:17.182714 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4287,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.183182 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling MajorDeltaCompactionOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=1.000000
I20260812 06:18:17.415060 11230 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.923s	user 1.820s	sys 0.166s
I20260812 06:18:17.422061 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: MajorDeltaCompactionOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.239s	user 0.179s	sys 0.052s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979750,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":4139,"dirs.run_cpu_time_us":1285,"dirs.run_wall_time_us":13821,"lbm_read_time_us":16593,"lbm_reads_lt_1ms":774,"lbm_write_time_us":40955,"lbm_writes_lt_1ms":743,"mutex_wait_us":2861,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":15104,"thread_start_us":87,"threads_started":1,"update_count":3500}
I20260812 06:18:17.422600 11893 maintenance_manager.cc:419] P 52bbf1a4f93a4dcc969f43e9264e3bd7: Scheduling FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb): perf score=18.063937
I20260812 06:18:17.446784 11230 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.031s	user 0.002s	sys 0.000s
I20260812 06:18:17.447427 11230 tablet_server.cc:179] TabletServer@127.10.247.129:0 shutting down...
I20260812 06:18:17.480954 11778 maintenance_manager.cc:643] P 52bbf1a4f93a4dcc969f43e9264e3bd7: FlushDeltaMemStoresOp(3108d7dbf4ed4983aa05f84fa26375cb) complete. Timing: real 0.058s	user 0.043s	sys 0.015s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":26044,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:17.481511 11230 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:17.481760 11230 tablet_replica.cc:333] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7: stopping tablet replica
I20260812 06:18:17.481906 11230 raft_consensus.cc:2243] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:17.482098 11230 raft_consensus.cc:2272] T 3108d7dbf4ed4983aa05f84fa26375cb P 52bbf1a4f93a4dcc969f43e9264e3bd7 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:17.485558 11230 tablet_server.cc:196] TabletServer@127.10.247.129:0 shutdown complete.
I20260812 06:18:17.488144 11230 master.cc:562] Master@127.10.247.190:39719 shutting down...
I20260812 06:18:17.491240 11230 raft_consensus.cc:2243] T 00000000000000000000000000000000 P ca18c1c09ef749429c27aeee3b1a4e9d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:17.491400 11230 raft_consensus.cc:2272] T 00000000000000000000000000000000 P ca18c1c09ef749429c27aeee3b1a4e9d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:17.491487 11230 tablet_replica.cc:333] T 00000000000000000000000000000000 P ca18c1c09ef749429c27aeee3b1a4e9d: stopping tablet replica
I20260812 06:18:17.503753 11230 master.cc:584] Master@127.10.247.190:39719 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5335 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10581 ms total)

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