[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:53.525499 12954 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.12.166.190:35111
I20260812 06:19:53.526554 12954 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:53.527168 12954 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:53.533846 12964 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:53.533938 12962 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:53.534044 12954 server_base.cc:1061] running on GCE node
W20260812 06:19:53.534288 12968 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:53.534782 12954 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:53.534875 12954 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:53.534907 12954 hybrid_clock.cc:648] HybridClock initialized: now 1786515593534905 us; error 0 us; skew 500 ppm
I20260812 06:19:53.536746 12954 webserver.cc:533] Webserver started at http://127.12.166.190:35495/ using document root <none> and password file <none>
I20260812 06:19:53.537273 12954 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:53.537330 12954 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:53.537539 12954 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:53.539311 12954 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/master-0-root/instance:
uuid: "cb7f1a87071248268d1193eb93a2e28b"
format_stamp: "Formatted at 2026-08-12 06:19:53 on dist-test-slave-xt4k"
I20260812 06:19:53.543277 12954 fs_manager.cc:696] Time spent creating directory manager: real 0.004s	user 0.002s	sys 0.004s
I20260812 06:19:53.545567 12975 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:53.546598 12954 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:19:53.546799 12954 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/master-0-root
uuid: "cb7f1a87071248268d1193eb93a2e28b"
format_stamp: "Formatted at 2026-08-12 06:19:53 on dist-test-slave-xt4k"
I20260812 06:19:53.546921 12954 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:53.561967 12954 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:53.562659 12954 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:53.562803 12954 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:53.570871 12954 rpc_server.cc:307] RPC server started. Bound to: 127.12.166.190:35111
I20260812 06:19:53.570928 13074 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.166.190:35111 every 8 connection(s)
I20260812 06:19:53.573252 13076 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:53.578815 13076 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P cb7f1a87071248268d1193eb93a2e28b: Bootstrap starting.
I20260812 06:19:53.581295 13076 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P cb7f1a87071248268d1193eb93a2e28b: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:53.582235 13076 log.cc:826] T 00000000000000000000000000000000 P cb7f1a87071248268d1193eb93a2e28b: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:53.584018 13076 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P cb7f1a87071248268d1193eb93a2e28b: No bootstrap required, opened a new log
I20260812 06:19:53.587155 13076 raft_consensus.cc:359] T 00000000000000000000000000000000 P cb7f1a87071248268d1193eb93a2e28b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cb7f1a87071248268d1193eb93a2e28b" member_type: VOTER }
I20260812 06:19:53.587325 13076 raft_consensus.cc:385] T 00000000000000000000000000000000 P cb7f1a87071248268d1193eb93a2e28b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:53.587373 13076 raft_consensus.cc:740] T 00000000000000000000000000000000 P cb7f1a87071248268d1193eb93a2e28b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: cb7f1a87071248268d1193eb93a2e28b, State: Initialized, Role: FOLLOWER
I20260812 06:19:53.587914 13076 consensus_queue.cc:260] T 00000000000000000000000000000000 P cb7f1a87071248268d1193eb93a2e28b [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: "cb7f1a87071248268d1193eb93a2e28b" member_type: VOTER }
I20260812 06:19:53.588050 13076 raft_consensus.cc:399] T 00000000000000000000000000000000 P cb7f1a87071248268d1193eb93a2e28b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:53.588105 13076 raft_consensus.cc:493] T 00000000000000000000000000000000 P cb7f1a87071248268d1193eb93a2e28b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:53.588198 13076 raft_consensus.cc:3060] T 00000000000000000000000000000000 P cb7f1a87071248268d1193eb93a2e28b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:53.589006 13076 raft_consensus.cc:515] T 00000000000000000000000000000000 P cb7f1a87071248268d1193eb93a2e28b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cb7f1a87071248268d1193eb93a2e28b" member_type: VOTER }
I20260812 06:19:53.589409 13076 leader_election.cc:304] T 00000000000000000000000000000000 P cb7f1a87071248268d1193eb93a2e28b [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: cb7f1a87071248268d1193eb93a2e28b; no voters: 
I20260812 06:19:53.589681 13076 leader_election.cc:290] T 00000000000000000000000000000000 P cb7f1a87071248268d1193eb93a2e28b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:53.589821 13082 raft_consensus.cc:2804] T 00000000000000000000000000000000 P cb7f1a87071248268d1193eb93a2e28b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:53.590037 13082 raft_consensus.cc:697] T 00000000000000000000000000000000 P cb7f1a87071248268d1193eb93a2e28b [term 1 LEADER]: Becoming Leader. State: Replica: cb7f1a87071248268d1193eb93a2e28b, State: Running, Role: LEADER
I20260812 06:19:53.590426 13082 consensus_queue.cc:237] T 00000000000000000000000000000000 P cb7f1a87071248268d1193eb93a2e28b [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: "cb7f1a87071248268d1193eb93a2e28b" member_type: VOTER }
I20260812 06:19:53.590615 13076 sys_catalog.cc:565] T 00000000000000000000000000000000 P cb7f1a87071248268d1193eb93a2e28b [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:53.592289 13085 sys_catalog.cc:455] T 00000000000000000000000000000000 P cb7f1a87071248268d1193eb93a2e28b [sys.catalog]: SysCatalogTable state changed. Reason: New leader cb7f1a87071248268d1193eb93a2e28b. Latest consensus state: current_term: 1 leader_uuid: "cb7f1a87071248268d1193eb93a2e28b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cb7f1a87071248268d1193eb93a2e28b" member_type: VOTER } }
I20260812 06:19:53.592437 13085 sys_catalog.cc:458] T 00000000000000000000000000000000 P cb7f1a87071248268d1193eb93a2e28b [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:53.592684 13083 sys_catalog.cc:455] T 00000000000000000000000000000000 P cb7f1a87071248268d1193eb93a2e28b [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "cb7f1a87071248268d1193eb93a2e28b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "cb7f1a87071248268d1193eb93a2e28b" member_type: VOTER } }
I20260812 06:19:53.592758 13083 sys_catalog.cc:458] T 00000000000000000000000000000000 P cb7f1a87071248268d1193eb93a2e28b [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:53.592777 13112 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:53.592856 12954 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:53.594985 13112 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:53.599212 13112 catalog_manager.cc:1383] Generated new cluster ID: 241b3657b6d642c98997e5b009ad6696
I20260812 06:19:53.599277 13112 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:53.620498 13112 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:53.621696 13112 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:53.637567 13112 catalog_manager.cc:6092] T 00000000000000000000000000000000 P cb7f1a87071248268d1193eb93a2e28b: Generated new TSK 0
I20260812 06:19:53.638396 13112 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:53.657706 12954 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:53.660463 13120 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:53.660575 13127 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:53.660542 13124 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:53.661233 12954 server_base.cc:1061] running on GCE node
I20260812 06:19:53.661443 12954 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:53.661487 12954 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:53.661507 12954 hybrid_clock.cc:648] HybridClock initialized: now 1786515593661508 us; error 0 us; skew 500 ppm
I20260812 06:19:53.662359 12954 webserver.cc:533] Webserver started at http://127.12.166.129:35373/ using document root <none> and password file <none>
I20260812 06:19:53.662533 12954 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:53.662581 12954 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:53.662657 12954 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:53.663050 12954 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/instance:
uuid: "dfa7b267beb94377ae65d0d04edce6ae"
format_stamp: "Formatted at 2026-08-12 06:19:53 on dist-test-slave-xt4k"
I20260812 06:19:53.664539 12954 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:53.665501 13134 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:53.665731 12954 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:53.665802 12954 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root
uuid: "dfa7b267beb94377ae65d0d04edce6ae"
format_stamp: "Formatted at 2026-08-12 06:19:53 on dist-test-slave-xt4k"
I20260812 06:19:53.665854 12954 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:53.679261 12954 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:53.679740 12954 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:53.680263 12954 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:53.681169 12954 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:53.681226 12954 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:53.681272 12954 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:53.681299 12954 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:53.687832 12954 rpc_server.cc:307] RPC server started. Bound to: 127.12.166.129:41935
I20260812 06:19:53.687881 13247 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.166.129:41935 every 8 connection(s)
I20260812 06:19:53.702931 13249 heartbeater.cc:344] Connected to a master server at 127.12.166.190:35111
I20260812 06:19:53.703222 13249 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:53.703714 13249 heartbeater.cc:507] Master 127.12.166.190:35111 requested a full tablet report, sending...
I20260812 06:19:53.705168 13007 ts_manager.cc:194] Registered new tserver with Master: dfa7b267beb94377ae65d0d04edce6ae (127.12.166.129:41935)
I20260812 06:19:53.705428 12954 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.01695263s
I20260812 06:19:53.706389 13007 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:53876
I20260812 06:19:53.716640 13007 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:53892:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:53.731035 13190 tablet_service.cc:1511] Processing CreateTablet for tablet 71491e270aad4a4aa4edaa7f0314108f (DEFAULT_TABLE table=heavy-update-compaction-test [id=a8f8bcb01d7c41c49386de7b963e65b4]), partition=
I20260812 06:19:53.731519 13190 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 71491e270aad4a4aa4edaa7f0314108f. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:53.734443 13277 tablet_bootstrap.cc:492] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Bootstrap starting.
I20260812 06:19:53.735520 13277 tablet_bootstrap.cc:654] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:53.736915 13277 tablet_bootstrap.cc:492] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: No bootstrap required, opened a new log
I20260812 06:19:53.737016 13277 ts_tablet_manager.cc:1403] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:53.737500 13277 raft_consensus.cc:359] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dfa7b267beb94377ae65d0d04edce6ae" member_type: VOTER last_known_addr { host: "127.12.166.129" port: 41935 } }
I20260812 06:19:53.737599 13277 raft_consensus.cc:385] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:53.737632 13277 raft_consensus.cc:740] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: dfa7b267beb94377ae65d0d04edce6ae, State: Initialized, Role: FOLLOWER
I20260812 06:19:53.737761 13277 consensus_queue.cc:260] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae [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: "dfa7b267beb94377ae65d0d04edce6ae" member_type: VOTER last_known_addr { host: "127.12.166.129" port: 41935 } }
I20260812 06:19:53.737833 13277 raft_consensus.cc:399] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:53.737887 13277 raft_consensus.cc:493] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:53.737941 13277 raft_consensus.cc:3060] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:53.738806 13277 raft_consensus.cc:515] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dfa7b267beb94377ae65d0d04edce6ae" member_type: VOTER last_known_addr { host: "127.12.166.129" port: 41935 } }
I20260812 06:19:53.738957 13277 leader_election.cc:304] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae [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: dfa7b267beb94377ae65d0d04edce6ae; no voters: 
I20260812 06:19:53.739151 13277 leader_election.cc:290] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:53.739260 13280 raft_consensus.cc:2804] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:53.739427 13280 raft_consensus.cc:697] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae [term 1 LEADER]: Becoming Leader. State: Replica: dfa7b267beb94377ae65d0d04edce6ae, State: Running, Role: LEADER
I20260812 06:19:53.739509 13277 ts_tablet_manager.cc:1434] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:53.739591 13280 consensus_queue.cc:237] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae [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: "dfa7b267beb94377ae65d0d04edce6ae" member_type: VOTER last_known_addr { host: "127.12.166.129" port: 41935 } }
I20260812 06:19:53.739915 13249 heartbeater.cc:499] Master 127.12.166.190:35111 was elected leader, sending a full tablet report...
I20260812 06:19:53.742566 13007 catalog_manager.cc:5719] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae reported cstate change: term changed from 0 to 1, leader changed from <none> to dfa7b267beb94377ae65d0d04edce6ae (127.12.166.129). New cstate: current_term: 1 leader_uuid: "dfa7b267beb94377ae65d0d04edce6ae" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dfa7b267beb94377ae65d0d04edce6ae" member_type: VOTER last_known_addr { host: "127.12.166.129" port: 41935 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:53.803594 12954 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.051s	user 0.024s	sys 0.000s
I20260812 06:19:53.938932 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushMRSOp(71491e270aad4a4aa4edaa7f0314108f): perf score=19.054940
I20260812 06:19:54.119014 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushMRSOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.180s	user 0.144s	sys 0.032s Metrics: {"bytes_written":14604838,"cfile_init":1,"compiler_manager_pool.queue_time_us":225,"delete_count":0,"dirs.queue_time_us":85,"dirs.run_cpu_time_us":246,"dirs.run_wall_time_us":943,"drs_written":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4,"lbm_write_time_us":45409,"lbm_writes_lt_1ms":813,"mutex_wait_us":180,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":389376,"thread_start_us":114,"threads_started":1,"update_count":1780}
I20260812 06:19:54.120261 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=1.196750
I20260812 06:19:54.134665 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.014s	user 0.010s	sys 0.000s Metrics: {"bytes_written":2994988,"delete_count":0,"lbm_write_time_us":4687,"lbm_writes_lt_1ms":76,"reinsert_count":0,"update_count":365}
I20260812 06:19:54.135192 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling LogGCOp(71491e270aad4a4aa4edaa7f0314108f): free 20743880 bytes of WAL
I20260812 06:19:54.135569 13147 log_reader.cc:385] T 71491e270aad4a4aa4edaa7f0314108f: removed 2 log segments from log reader
I20260812 06:19:54.135687 13147 log.cc:1079] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/71491e270aad4a4aa4edaa7f0314108f/wal-000000001 (ops 1-6)
I20260812 06:19:54.135790 13147 log.cc:1079] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/71491e270aad4a4aa4edaa7f0314108f/wal-000000002 (ops 7-11)
I20260812 06:19:54.141009 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: LogGCOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.006s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:19:54.141413 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling UndoDeltaBlockGCOp(71491e270aad4a4aa4edaa7f0314108f): 16411392 bytes on disk
I20260812 06:19:54.142102 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: UndoDeltaBlockGCOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":81,"lbm_reads_lt_1ms":4}
I20260812 06:19:54.142625 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=1.196750
I20260812 06:19:54.153026 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.010s	user 0.004s	sys 0.006s Metrics: {"bytes_written":2912930,"delete_count":0,"lbm_write_time_us":3699,"lbm_writes_lt_1ms":74,"reinsert_count":0,"update_count":355}
I20260812 06:19:54.153534 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f): perf score=1.000000
I20260812 06:19:54.319224 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.165s	user 0.113s	sys 0.052s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774756,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":876,"lbm_read_time_us":11086,"lbm_reads_lt_1ms":569,"lbm_write_time_us":28349,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1920,"thread_start_us":301,"threads_started":5,"update_count":2500}
I20260812 06:19:54.319720 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=10.126437
I20260812 06:19:54.363935 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.044s	user 0.018s	sys 0.015s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":15432,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:54.364513 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=2.188937
I20260812 06:19:54.379408 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5321,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.379901 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f): perf score=1.000000
I20260812 06:19:54.510265 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.130s	user 0.107s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":148,"lbm_read_time_us":10149,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20479,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:54.510715 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=10.126437
I20260812 06:19:54.545322 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.034s	user 0.017s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14245,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:54.545878 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f): perf score=1.000000
I20260812 06:19:54.652527 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.106s	user 0.083s	sys 0.023s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":179,"lbm_read_time_us":7278,"lbm_reads_lt_1ms":363,"lbm_write_time_us":17485,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:19:54.653033 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=10.126437
I20260812 06:19:54.682891 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.030s	user 0.013s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12222,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:54.683496 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f): perf score=1.000000
I20260812 06:19:54.801944 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.118s	user 0.093s	sys 0.020s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":893,"lbm_read_time_us":7322,"lbm_reads_lt_1ms":363,"lbm_write_time_us":18204,"lbm_writes_lt_1ms":343,"mutex_wait_us":490,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":1500}
I20260812 06:19:54.803480 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=10.126437
I20260812 06:19:54.845957 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.042s	user 0.017s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15679,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:54.846450 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=2.188937
I20260812 06:19:54.856555 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.010s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3729,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.857141 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f): perf score=1.000000
I20260812 06:19:54.974110 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.117s	user 0.096s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":677,"lbm_read_time_us":7849,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23026,"lbm_writes_lt_1ms":443,"mutex_wait_us":287,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8576,"update_count":2000}
I20260812 06:19:54.974653 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=10.126437
I20260812 06:19:55.013345 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.038s	user 0.013s	sys 0.015s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":12372,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:55.013900 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=2.188937
I20260812 06:19:55.024304 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3833,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.024937 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f): perf score=1.000000
I20260812 06:19:55.145857 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.121s	user 0.084s	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":220,"lbm_read_time_us":7654,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23591,"lbm_writes_lt_1ms":443,"mutex_wait_us":33,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:19:55.146451 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=10.126437
I20260812 06:19:55.197285 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.051s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14340,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:55.197924 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=2.188937
I20260812 06:19:55.208151 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3767,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.208701 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f): perf score=1.000000
I20260812 06:19:55.345754 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.137s	user 0.087s	sys 0.048s 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":248,"lbm_read_time_us":10239,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21642,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:55.346447 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=10.126437
I20260812 06:19:55.384720 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.038s	user 0.028s	sys 0.003s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13013,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:55.385262 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=2.188937
I20260812 06:19:55.400269 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5435,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.400836 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushMRSOp(71491e270aad4a4aa4edaa7f0314108f): perf score=1.000000
I20260812 06:19:55.428220 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushMRSOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.027s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":232,"dirs.run_wall_time_us":1313,"drs_written":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1728,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:55.429041 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling LogGCOp(71491e270aad4a4aa4edaa7f0314108f): free 124257258 bytes of WAL
I20260812 06:19:55.429260 13147 log_reader.cc:385] T 71491e270aad4a4aa4edaa7f0314108f: removed 12 log segments from log reader
I20260812 06:19:55.429302 13147 log.cc:1079] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/71491e270aad4a4aa4edaa7f0314108f/wal-000000003 (ops 12-16)
I20260812 06:19:55.429330 13147 log.cc:1079] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/71491e270aad4a4aa4edaa7f0314108f/wal-000000004 (ops 17-21)
I20260812 06:19:55.429360 13147 log.cc:1079] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/71491e270aad4a4aa4edaa7f0314108f/wal-000000005 (ops 22-26)
I20260812 06:19:55.429390 13147 log.cc:1079] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/71491e270aad4a4aa4edaa7f0314108f/wal-000000006 (ops 27-31)
I20260812 06:19:55.429414 13147 log.cc:1079] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/71491e270aad4a4aa4edaa7f0314108f/wal-000000007 (ops 32-36)
I20260812 06:19:55.429446 13147 log.cc:1079] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/71491e270aad4a4aa4edaa7f0314108f/wal-000000008 (ops 37-41)
I20260812 06:19:55.429486 13147 log.cc:1079] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/71491e270aad4a4aa4edaa7f0314108f/wal-000000009 (ops 42-46)
I20260812 06:19:55.429518 13147 log.cc:1079] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/71491e270aad4a4aa4edaa7f0314108f/wal-000000010 (ops 47-51)
I20260812 06:19:55.429549 13147 log.cc:1079] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/71491e270aad4a4aa4edaa7f0314108f/wal-000000011 (ops 52-56)
I20260812 06:19:55.429581 13147 log.cc:1079] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/71491e270aad4a4aa4edaa7f0314108f/wal-000000012 (ops 57-61)
I20260812 06:19:55.429612 13147 log.cc:1079] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/71491e270aad4a4aa4edaa7f0314108f/wal-000000013 (ops 62-66)
I20260812 06:19:55.429643 13147 log.cc:1079] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/71491e270aad4a4aa4edaa7f0314108f/wal-000000014 (ops 67-70)
I20260812 06:19:55.452768 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: LogGCOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.024s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:19:55.453163 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=3.181125
I20260812 06:19:55.477495 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.024s	user 0.008s	sys 0.012s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":5167,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:55.478014 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=2.188937
I20260812 06:19:55.487673 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.009s	user 0.002s	sys 0.006s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3419,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:55.488124 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f): perf score=1.000000
I20260812 06:19:55.678006 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.190s	user 0.107s	sys 0.068s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":5137,"lbm_read_time_us":13045,"lbm_reads_lt_1ms":674,"lbm_write_time_us":30176,"lbm_writes_lt_1ms":643,"mutex_wait_us":2336,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":73,"threads_started":1,"update_count":3000}
I20260812 06:19:55.678933 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling UndoDeltaBlockGCOp(71491e270aad4a4aa4edaa7f0314108f): 483 bytes on disk
I20260812 06:19:55.679399 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: UndoDeltaBlockGCOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:19:55.679896 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=14.095187
I20260812 06:19:55.732139 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.052s	user 0.038s	sys 0.008s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":18087,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:55.732740 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=2.188937
I20260812 06:19:55.747764 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5722,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.748267 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f): perf score=1.000000
I20260812 06:19:55.911118 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.163s	user 0.098s	sys 0.065s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":561,"lbm_read_time_us":12511,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27983,"lbm_writes_lt_1ms":543,"mutex_wait_us":306,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":2500}
I20260812 06:19:55.911718 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=10.126437
I20260812 06:19:55.955056 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.042s	user 0.030s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19658,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":300,"reinsert_count":0,"update_count":1500}
I20260812 06:19:55.955658 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=2.188937
I20260812 06:19:55.969676 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5029,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.970176 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f): perf score=1.000000
I20260812 06:19:56.094322 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.124s	user 0.086s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":547,"lbm_read_time_us":7373,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21894,"lbm_writes_lt_1ms":443,"mutex_wait_us":79,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:56.096275 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=11.118625
I20260812 06:19:56.141095 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.045s	user 0.028s	sys 0.016s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":20170,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:19:56.141675 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=2.188937
I20260812 06:19:56.154117 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4162,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:56.154634 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f): perf score=1.000000
I20260812 06:19:56.270489 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.116s	user 0.095s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1533,"lbm_read_time_us":8766,"lbm_reads_lt_1ms":464,"lbm_write_time_us":20810,"lbm_writes_lt_1ms":443,"mutex_wait_us":1214,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":59264,"update_count":2000}
I20260812 06:19:56.271311 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=10.126437
I20260812 06:19:56.303360 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.032s	user 0.022s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13793,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:56.303894 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=2.188937
I20260812 06:19:56.315403 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4037,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.316161 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f): perf score=1.000000
I20260812 06:19:56.432727 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.116s	user 0.091s	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":884,"lbm_read_time_us":7387,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22755,"lbm_writes_lt_1ms":443,"mutex_wait_us":20,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":22144,"update_count":2000}
I20260812 06:19:56.433254 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=10.126437
I20260812 06:19:56.473547 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.040s	user 0.020s	sys 0.018s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":14230,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:56.474186 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=2.188937
I20260812 06:19:56.484303 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3850,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.484855 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f): perf score=1.000000
I20260812 06:19:56.625639 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.141s	user 0.090s	sys 0.050s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":296,"lbm_read_time_us":10268,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22973,"lbm_writes_lt_1ms":443,"mutex_wait_us":66,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:56.626252 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=10.126437
I20260812 06:19:56.666435 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.040s	user 0.027s	sys 0.005s Metrics: {"bytes_written":12307494,"delete_count":0,"lbm_write_time_us":14524,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:56.666929 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=2.188937
I20260812 06:19:56.682045 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5508,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.682753 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f): perf score=1.000000
I20260812 06:19:56.800127 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.117s	user 0.088s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672281,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1181,"lbm_read_time_us":8351,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23076,"lbm_writes_lt_1ms":443,"mutex_wait_us":538,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14080,"update_count":2000}
I20260812 06:19:56.800822 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=10.126437
I20260812 06:19:56.834270 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.033s	user 0.029s	sys 0.001s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14020,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:56.834789 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=2.188937
I20260812 06:19:56.849473 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5297,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.850042 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushMRSOp(71491e270aad4a4aa4edaa7f0314108f): perf score=1.000000
I20260812 06:19:56.882783 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushMRSOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.033s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":215,"dirs.run_wall_time_us":1642,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1540,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:56.883526 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling LogGCOp(71491e270aad4a4aa4edaa7f0314108f): free 129773581 bytes of WAL
I20260812 06:19:56.883750 13147 log_reader.cc:385] T 71491e270aad4a4aa4edaa7f0314108f: removed 13 log segments from log reader
I20260812 06:19:56.883795 13147 log.cc:1079] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/71491e270aad4a4aa4edaa7f0314108f/wal-000000015 (ops 71-75)
I20260812 06:19:56.883823 13147 log.cc:1079] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/71491e270aad4a4aa4edaa7f0314108f/wal-000000016 (ops 76-80)
I20260812 06:19:56.883854 13147 log.cc:1079] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/71491e270aad4a4aa4edaa7f0314108f/wal-000000017 (ops 81-85)
I20260812 06:19:56.883885 13147 log.cc:1079] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/71491e270aad4a4aa4edaa7f0314108f/wal-000000018 (ops 86-90)
I20260812 06:19:56.883919 13147 log.cc:1079] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/71491e270aad4a4aa4edaa7f0314108f/wal-000000019 (ops 91-95)
I20260812 06:19:56.883950 13147 log.cc:1079] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/71491e270aad4a4aa4edaa7f0314108f/wal-000000020 (ops 96-100)
I20260812 06:19:56.883981 13147 log.cc:1079] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/71491e270aad4a4aa4edaa7f0314108f/wal-000000021 (ops 101-105)
I20260812 06:19:56.884013 13147 log.cc:1079] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/71491e270aad4a4aa4edaa7f0314108f/wal-000000022 (ops 106-110)
I20260812 06:19:56.884044 13147 log.cc:1079] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/71491e270aad4a4aa4edaa7f0314108f/wal-000000023 (ops 111-115)
I20260812 06:19:56.884075 13147 log.cc:1079] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/71491e270aad4a4aa4edaa7f0314108f/wal-000000024 (ops 116-120)
I20260812 06:19:56.884107 13147 log.cc:1079] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/71491e270aad4a4aa4edaa7f0314108f/wal-000000025 (ops 121-124)
I20260812 06:19:56.884136 13147 log.cc:1079] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/71491e270aad4a4aa4edaa7f0314108f/wal-000000026 (ops 125-129)
I20260812 06:19:56.884167 13147 log.cc:1079] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/71491e270aad4a4aa4edaa7f0314108f/wal-000000027 (ops 130-134)
I20260812 06:19:56.907927 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: LogGCOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.024s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:19:56.908313 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling UndoDeltaBlockGCOp(71491e270aad4a4aa4edaa7f0314108f): 482 bytes on disk
I20260812 06:19:56.908758 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: UndoDeltaBlockGCOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:19:56.909248 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=3.181125
I20260812 06:19:56.921787 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4800074,"delete_count":0,"lbm_write_time_us":4688,"lbm_writes_lt_1ms":120,"reinsert_count":0,"update_count":585}
I20260812 06:19:56.922200 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=2.188937
I20260812 06:19:56.934999 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.013s	user 0.007s	sys 0.003s Metrics: {"bytes_written":3405230,"delete_count":0,"lbm_write_time_us":4476,"lbm_writes_lt_1ms":86,"reinsert_count":0,"update_count":415}
I20260812 06:19:56.935554 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f): perf score=1.000000
I20260812 06:19:57.100760 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.165s	user 0.117s	sys 0.040s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":788,"lbm_read_time_us":12603,"lbm_reads_lt_1ms":674,"lbm_write_time_us":29669,"lbm_writes_lt_1ms":643,"mutex_wait_us":280,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3328,"thread_start_us":73,"threads_started":1,"update_count":3000}
I20260812 06:19:57.103012 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=14.095187
I20260812 06:19:57.152114 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.049s	user 0.028s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20873,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.152678 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=2.188937
I20260812 06:19:57.164799 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.012s	user 0.011s	sys 0.000s 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:19:57.165416 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f): perf score=1.000000
I20260812 06:19:57.319608 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.154s	user 0.115s	sys 0.029s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1021,"lbm_read_time_us":9295,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26888,"lbm_writes_lt_1ms":543,"mutex_wait_us":323,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13568,"update_count":2500}
I20260812 06:19:57.320116 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=14.095187
I20260812 06:19:57.358856 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.039s	user 0.019s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17038,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.359338 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f): perf score=1.000000
I20260812 06:19:57.494491 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.135s	user 0.098s	sys 0.032s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":970,"lbm_read_time_us":8178,"lbm_reads_lt_1ms":467,"lbm_write_time_us":21492,"lbm_writes_lt_1ms":443,"mutex_wait_us":314,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:57.495290 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=11.118625
I20260812 06:19:57.524115 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.029s	user 0.005s	sys 0.020s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":11730,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:57.524777 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=2.188937
I20260812 06:19:57.536511 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.012s	user 0.008s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3822,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:57.537119 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f): perf score=1.000000
I20260812 06:19:57.653759 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.116s	user 0.103s	sys 0.011s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672270,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":119,"lbm_read_time_us":7226,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21576,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13696,"update_count":2000}
I20260812 06:19:57.654320 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=10.126437
I20260812 06:19:57.683180 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.029s	user 0.021s	sys 0.005s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":11962,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:57.683732 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=2.188937
I20260812 06:19:57.698900 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5651,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.699518 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f): perf score=1.000000
I20260812 06:19:57.823555 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.124s	user 0.116s	sys 0.008s 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":994,"lbm_read_time_us":9361,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22734,"lbm_writes_lt_1ms":443,"mutex_wait_us":290,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2000}
I20260812 06:19:57.824147 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=10.126437
I20260812 06:19:57.863639 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.039s	user 0.008s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13191,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:57.864207 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=2.188937
I20260812 06:19:57.879674 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5158,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.880285 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f): perf score=1.000000
I20260812 06:19:58.000854 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.120s	user 0.092s	sys 0.028s 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":305,"lbm_read_time_us":9841,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21454,"lbm_writes_lt_1ms":443,"mutex_wait_us":46,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:19:58.001402 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=10.126437
I20260812 06:19:58.052035 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.050s	user 0.024s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14491,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:58.052634 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=2.188937
I20260812 06:19:58.067342 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5468,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.067875 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f): perf score=1.000000
I20260812 06:19:58.206215 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.138s	user 0.098s	sys 0.040s 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":280,"lbm_read_time_us":10901,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21872,"lbm_writes_lt_1ms":443,"mutex_wait_us":20,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":2000}
I20260812 06:19:58.206919 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=10.126437
I20260812 06:19:58.248508 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.041s	user 0.019s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":12633,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:58.249078 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=2.188937
I20260812 06:19:58.259742 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3765,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.260370 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushMRSOp(71491e270aad4a4aa4edaa7f0314108f): perf score=1.000000
I20260812 06:19:58.293648 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushMRSOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.033s	user 0.031s	sys 0.001s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":242,"dirs.run_wall_time_us":1264,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1586,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:58.294411 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling LogGCOp(71491e270aad4a4aa4edaa7f0314108f): free 124257509 bytes of WAL
I20260812 06:19:58.294641 13147 log_reader.cc:385] T 71491e270aad4a4aa4edaa7f0314108f: removed 12 log segments from log reader
I20260812 06:19:58.294689 13147 log.cc:1079] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/71491e270aad4a4aa4edaa7f0314108f/wal-000000028 (ops 135-139)
I20260812 06:19:58.294718 13147 log.cc:1079] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/71491e270aad4a4aa4edaa7f0314108f/wal-000000029 (ops 140-144)
I20260812 06:19:58.294744 13147 log.cc:1079] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/71491e270aad4a4aa4edaa7f0314108f/wal-000000030 (ops 145-149)
I20260812 06:19:58.294773 13147 log.cc:1079] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/71491e270aad4a4aa4edaa7f0314108f/wal-000000031 (ops 150-154)
I20260812 06:19:58.294804 13147 log.cc:1079] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/71491e270aad4a4aa4edaa7f0314108f/wal-000000032 (ops 155-159)
I20260812 06:19:58.294842 13147 log.cc:1079] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/71491e270aad4a4aa4edaa7f0314108f/wal-000000033 (ops 160-164)
I20260812 06:19:58.294874 13147 log.cc:1079] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/71491e270aad4a4aa4edaa7f0314108f/wal-000000034 (ops 165-169)
I20260812 06:19:58.294895 13147 log.cc:1079] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/71491e270aad4a4aa4edaa7f0314108f/wal-000000035 (ops 170-174)
I20260812 06:19:58.294910 13147 log.cc:1079] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/71491e270aad4a4aa4edaa7f0314108f/wal-000000036 (ops 175-178)
I20260812 06:19:58.294940 13147 log.cc:1079] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/71491e270aad4a4aa4edaa7f0314108f/wal-000000037 (ops 179-183)
I20260812 06:19:58.294972 13147 log.cc:1079] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/71491e270aad4a4aa4edaa7f0314108f/wal-000000038 (ops 184-188)
I20260812 06:19:58.295013 13147 log.cc:1079] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/71491e270aad4a4aa4edaa7f0314108f/wal-000000039 (ops 189-193)
I20260812 06:19:58.316642 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: LogGCOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.022s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:19:58.317045 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=3.181125
I20260812 06:19:58.336702 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.019s	user 0.007s	sys 0.012s Metrics: {"bytes_written":4635977,"delete_count":0,"lbm_write_time_us":4837,"lbm_writes_lt_1ms":116,"reinsert_count":0,"update_count":565}
I20260812 06:19:58.337291 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f): perf score=2.188937
I20260812 06:19:58.346805 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: FlushDeltaMemStoresOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3569330,"delete_count":0,"lbm_write_time_us":3384,"lbm_writes_lt_1ms":90,"reinsert_count":0,"update_count":435}
I20260812 06:19:58.347429 13254 maintenance_manager.cc:419] P dfa7b267beb94377ae65d0d04edce6ae: Scheduling MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f): perf score=1.000000
I20260812 06:19:58.395044 12954 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.591s	user 1.651s	sys 0.186s
I20260812 06:19:58.486335 12954 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.091s	user 0.001s	sys 0.001s
I20260812 06:19:58.486959 12954 tablet_server.cc:179] TabletServer@127.12.166.129:0 shutting down...
I20260812 06:19:58.514045 13147 maintenance_manager.cc:643] P dfa7b267beb94377ae65d0d04edce6ae: MajorDeltaCompactionOp(71491e270aad4a4aa4edaa7f0314108f) complete. Timing: real 0.166s	user 0.110s	sys 0.056s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877329,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":228,"lbm_read_time_us":12878,"lbm_reads_lt_1ms":670,"lbm_write_time_us":26047,"lbm_writes_lt_1ms":643,"mutex_wait_us":25,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":60544,"thread_start_us":76,"threads_started":1,"update_count":3000}
I20260812 06:19:58.514861 12954 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:58.515333 12954 tablet_replica.cc:333] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae: stopping tablet replica
I20260812 06:19:58.515549 12954 raft_consensus.cc:2243] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:58.515771 12954 raft_consensus.cc:2272] T 71491e270aad4a4aa4edaa7f0314108f P dfa7b267beb94377ae65d0d04edce6ae [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:58.531675 12954 tablet_server.cc:196] TabletServer@127.12.166.129:0 shutdown complete.
I20260812 06:19:58.565352 12954 master.cc:562] Master@127.12.166.190:35111 shutting down...
I20260812 06:19:58.568835 12954 raft_consensus.cc:2243] T 00000000000000000000000000000000 P cb7f1a87071248268d1193eb93a2e28b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:58.569011 12954 raft_consensus.cc:2272] T 00000000000000000000000000000000 P cb7f1a87071248268d1193eb93a2e28b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:58.569090 12954 tablet_replica.cc:333] T 00000000000000000000000000000000 P cb7f1a87071248268d1193eb93a2e28b: stopping tablet replica
I20260812 06:19:58.581197 12954 master.cc:584] Master@127.12.166.190:35111 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5128 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:58.665884 12954 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.12.166.190:34081
I20260812 06:19:58.666301 12954 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:58.668504 13315 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:58.668506 13322 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:58.668591 12954 server_base.cc:1061] running on GCE node
W20260812 06:19:58.668540 13317 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:58.668828 12954 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:58.668867 12954 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:58.668881 12954 hybrid_clock.cc:648] HybridClock initialized: now 1786515598668881 us; error 0 us; skew 500 ppm
I20260812 06:19:58.669657 12954 webserver.cc:533] Webserver started at http://127.12.166.190:43475/ using document root <none> and password file <none>
I20260812 06:19:58.669791 12954 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:58.669847 12954 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:58.669924 12954 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:58.670305 12954 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/master-0-root/instance:
uuid: "5bca116f36a74bd3b22c0cbbe752b148"
format_stamp: "Formatted at 2026-08-12 06:19:58 on dist-test-slave-xt4k"
I20260812 06:19:58.671743 12954 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:58.672833 13331 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:58.673092 12954 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:58.673162 12954 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/master-0-root
uuid: "5bca116f36a74bd3b22c0cbbe752b148"
format_stamp: "Formatted at 2026-08-12 06:19:58 on dist-test-slave-xt4k"
I20260812 06:19:58.673218 12954 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:58.677538 12954 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:58.677816 12954 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:58.681779 12954 rpc_server.cc:307] RPC server started. Bound to: 127.12.166.190:34081
I20260812 06:19:58.686173 13438 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.166.190:34081 every 8 connection(s)
I20260812 06:19:58.686641 13440 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:58.688323 13440 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5bca116f36a74bd3b22c0cbbe752b148: Bootstrap starting.
I20260812 06:19:58.689095 13440 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 5bca116f36a74bd3b22c0cbbe752b148: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:58.690061 13440 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5bca116f36a74bd3b22c0cbbe752b148: No bootstrap required, opened a new log
I20260812 06:19:58.690423 13440 raft_consensus.cc:359] T 00000000000000000000000000000000 P 5bca116f36a74bd3b22c0cbbe752b148 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5bca116f36a74bd3b22c0cbbe752b148" member_type: VOTER }
I20260812 06:19:58.690506 13440 raft_consensus.cc:385] T 00000000000000000000000000000000 P 5bca116f36a74bd3b22c0cbbe752b148 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:58.690527 13440 raft_consensus.cc:740] T 00000000000000000000000000000000 P 5bca116f36a74bd3b22c0cbbe752b148 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 5bca116f36a74bd3b22c0cbbe752b148, State: Initialized, Role: FOLLOWER
I20260812 06:19:58.690629 13440 consensus_queue.cc:260] T 00000000000000000000000000000000 P 5bca116f36a74bd3b22c0cbbe752b148 [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: "5bca116f36a74bd3b22c0cbbe752b148" member_type: VOTER }
I20260812 06:19:58.690686 13440 raft_consensus.cc:399] T 00000000000000000000000000000000 P 5bca116f36a74bd3b22c0cbbe752b148 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:58.690707 13440 raft_consensus.cc:493] T 00000000000000000000000000000000 P 5bca116f36a74bd3b22c0cbbe752b148 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:58.690744 13440 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 5bca116f36a74bd3b22c0cbbe752b148 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:58.691399 13440 raft_consensus.cc:515] T 00000000000000000000000000000000 P 5bca116f36a74bd3b22c0cbbe752b148 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5bca116f36a74bd3b22c0cbbe752b148" member_type: VOTER }
I20260812 06:19:58.691515 13440 leader_election.cc:304] T 00000000000000000000000000000000 P 5bca116f36a74bd3b22c0cbbe752b148 [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: 5bca116f36a74bd3b22c0cbbe752b148; no voters: 
I20260812 06:19:58.691692 13440 leader_election.cc:290] T 00000000000000000000000000000000 P 5bca116f36a74bd3b22c0cbbe752b148 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:58.691797 13444 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 5bca116f36a74bd3b22c0cbbe752b148 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:58.691982 13444 raft_consensus.cc:697] T 00000000000000000000000000000000 P 5bca116f36a74bd3b22c0cbbe752b148 [term 1 LEADER]: Becoming Leader. State: Replica: 5bca116f36a74bd3b22c0cbbe752b148, State: Running, Role: LEADER
I20260812 06:19:58.692106 13440 sys_catalog.cc:565] T 00000000000000000000000000000000 P 5bca116f36a74bd3b22c0cbbe752b148 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:58.692129 13444 consensus_queue.cc:237] T 00000000000000000000000000000000 P 5bca116f36a74bd3b22c0cbbe752b148 [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: "5bca116f36a74bd3b22c0cbbe752b148" member_type: VOTER }
I20260812 06:19:58.692564 13445 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5bca116f36a74bd3b22c0cbbe752b148 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "5bca116f36a74bd3b22c0cbbe752b148" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5bca116f36a74bd3b22c0cbbe752b148" member_type: VOTER } }
I20260812 06:19:58.692589 13446 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5bca116f36a74bd3b22c0cbbe752b148 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 5bca116f36a74bd3b22c0cbbe752b148. Latest consensus state: current_term: 1 leader_uuid: "5bca116f36a74bd3b22c0cbbe752b148" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5bca116f36a74bd3b22c0cbbe752b148" member_type: VOTER } }
I20260812 06:19:58.692742 13446 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5bca116f36a74bd3b22c0cbbe752b148 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:58.692720 13445 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5bca116f36a74bd3b22c0cbbe752b148 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:58.693233 13455 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:58.693979 13455 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:58.694175 12954 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:58.695713 13455 catalog_manager.cc:1383] Generated new cluster ID: 91e8e5027277462897070655c1b6be8c
I20260812 06:19:58.695770 13455 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:58.707393 13455 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:58.707939 13455 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:58.711603 13455 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 5bca116f36a74bd3b22c0cbbe752b148: Generated new TSK 0
I20260812 06:19:58.711747 13455 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:58.726559 12954 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:58.728544 13477 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:58.728662 13474 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:58.728746 12954 server_base.cc:1061] running on GCE node
W20260812 06:19:58.728564 13479 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:58.728989 12954 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:58.729045 12954 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:58.729060 12954 hybrid_clock.cc:648] HybridClock initialized: now 1786515598729060 us; error 0 us; skew 500 ppm
I20260812 06:19:58.729866 12954 webserver.cc:533] Webserver started at http://127.12.166.129:36173/ using document root <none> and password file <none>
I20260812 06:19:58.730038 12954 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:58.730093 12954 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:58.730167 12954 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:58.730537 12954 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/instance:
uuid: "a83e073df85048d6a54013fbd0a714b1"
format_stamp: "Formatted at 2026-08-12 06:19:58 on dist-test-slave-xt4k"
I20260812 06:19:58.732308 12954 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:58.733275 13487 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:58.733580 12954 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:58.733652 12954 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root
uuid: "a83e073df85048d6a54013fbd0a714b1"
format_stamp: "Formatted at 2026-08-12 06:19:58 on dist-test-slave-xt4k"
I20260812 06:19:58.733729 12954 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:58.746659 12954 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:58.747004 12954 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:58.747273 12954 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:58.747709 12954 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:58.747746 12954 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:58.747787 12954 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:58.747816 12954 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:58.752174 12954 rpc_server.cc:307] RPC server started. Bound to: 127.12.166.129:36717
I20260812 06:19:58.752197 13613 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.166.129:36717 every 8 connection(s)
I20260812 06:19:58.759743 13620 heartbeater.cc:344] Connected to a master server at 127.12.166.190:34081
I20260812 06:19:58.759848 13620 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:58.760044 13620 heartbeater.cc:507] Master 127.12.166.190:34081 requested a full tablet report, sending...
I20260812 06:19:58.760855 13365 ts_manager.cc:194] Registered new tserver with Master: a83e073df85048d6a54013fbd0a714b1 (127.12.166.129:36717)
I20260812 06:19:58.761529 12954 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008960685s
I20260812 06:19:58.761781 13365 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:44290
I20260812 06:19:58.772663 13365 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:44292:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:58.784876 13539 tablet_service.cc:1511] Processing CreateTablet for tablet 6991badf6bb54de684e5f2dfd10e4d83 (DEFAULT_TABLE table=heavy-update-compaction-test [id=f52eb07a348240fe8e6c074e30c7a881]), partition=
I20260812 06:19:58.785192 13539 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 6991badf6bb54de684e5f2dfd10e4d83. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:58.787691 13639 tablet_bootstrap.cc:492] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Bootstrap starting.
I20260812 06:19:58.788763 13639 tablet_bootstrap.cc:654] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:58.789899 13639 tablet_bootstrap.cc:492] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: No bootstrap required, opened a new log
I20260812 06:19:58.789985 13639 ts_tablet_manager.cc:1403] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:58.790336 13639 raft_consensus.cc:359] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a83e073df85048d6a54013fbd0a714b1" member_type: VOTER last_known_addr { host: "127.12.166.129" port: 36717 } }
I20260812 06:19:58.790416 13639 raft_consensus.cc:385] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:58.790444 13639 raft_consensus.cc:740] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a83e073df85048d6a54013fbd0a714b1, State: Initialized, Role: FOLLOWER
I20260812 06:19:58.790542 13639 consensus_queue.cc:260] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1 [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: "a83e073df85048d6a54013fbd0a714b1" member_type: VOTER last_known_addr { host: "127.12.166.129" port: 36717 } }
I20260812 06:19:58.790594 13639 raft_consensus.cc:399] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:58.790616 13639 raft_consensus.cc:493] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:58.790643 13639 raft_consensus.cc:3060] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:58.791288 13639 raft_consensus.cc:515] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a83e073df85048d6a54013fbd0a714b1" member_type: VOTER last_known_addr { host: "127.12.166.129" port: 36717 } }
I20260812 06:19:58.791401 13639 leader_election.cc:304] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1 [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: a83e073df85048d6a54013fbd0a714b1; no voters: 
I20260812 06:19:58.792455 13639 leader_election.cc:290] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:58.794389 13642 raft_consensus.cc:2804] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:58.794524 13620 heartbeater.cc:499] Master 127.12.166.190:34081 was elected leader, sending a full tablet report...
I20260812 06:19:58.794584 13642 raft_consensus.cc:697] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1 [term 1 LEADER]: Becoming Leader. State: Replica: a83e073df85048d6a54013fbd0a714b1, State: Running, Role: LEADER
I20260812 06:19:58.794723 13642 consensus_queue.cc:237] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1 [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: "a83e073df85048d6a54013fbd0a714b1" member_type: VOTER last_known_addr { host: "127.12.166.129" port: 36717 } }
I20260812 06:19:58.794512 13639 ts_tablet_manager.cc:1434] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Time spent starting tablet: real 0.004s	user 0.002s	sys 0.003s
I20260812 06:19:58.796078 13365 catalog_manager.cc:5719] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1 reported cstate change: term changed from 0 to 1, leader changed from <none> to a83e073df85048d6a54013fbd0a714b1 (127.12.166.129). New cstate: current_term: 1 leader_uuid: "a83e073df85048d6a54013fbd0a714b1" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a83e073df85048d6a54013fbd0a714b1" member_type: VOTER last_known_addr { host: "127.12.166.129" port: 36717 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:58.859357 12954 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.058s	user 0.018s	sys 0.010s
I20260812 06:19:59.003129 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushMRSOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=19.054940
I20260812 06:19:59.151876 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushMRSOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.148s	user 0.094s	sys 0.051s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":208,"dirs.run_wall_time_us":762,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":33873,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:19:59.152690 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling LogGCOp(6991badf6bb54de684e5f2dfd10e4d83): free 20743880 bytes of WAL
I20260812 06:19:59.152959 13501 log_reader.cc:385] T 6991badf6bb54de684e5f2dfd10e4d83: removed 2 log segments from log reader
I20260812 06:19:59.153007 13501 log.cc:1079] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/6991badf6bb54de684e5f2dfd10e4d83/wal-000000001 (ops 1-6)
I20260812 06:19:59.153038 13501 log.cc:1079] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/6991badf6bb54de684e5f2dfd10e4d83/wal-000000002 (ops 7-11)
I20260812 06:19:59.156750 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: LogGCOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.004s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:19:59.157119 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling UndoDeltaBlockGCOp(6991badf6bb54de684e5f2dfd10e4d83): 16411393 bytes on disk
I20260812 06:19:59.157567 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: UndoDeltaBlockGCOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:19:59.158038 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=2.188937
I20260812 06:19:59.169404 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3882,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.169845 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=1.000000
I20260812 06:19:59.310034 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.140s	user 0.090s	sys 0.049s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":338,"lbm_read_time_us":10174,"lbm_reads_lt_1ms":468,"lbm_write_time_us":21428,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":388,"threads_started":5,"update_count":2000}
I20260812 06:19:59.310540 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=10.126437
I20260812 06:19:59.340329 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.030s	user 0.019s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12701,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:59.340884 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=2.188937
I20260812 06:19:59.352263 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4257,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.352824 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=1.000000
I20260812 06:19:59.474773 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.122s	user 0.108s	sys 0.013s 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":817,"lbm_read_time_us":8343,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23524,"lbm_writes_lt_1ms":443,"mutex_wait_us":277,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":118016,"update_count":2000}
I20260812 06:19:59.475256 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=10.126437
I20260812 06:19:59.519762 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.044s	user 0.026s	sys 0.003s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13993,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:59.520308 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=2.188937
I20260812 06:19:59.530318 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3615,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.530841 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=1.000000
I20260812 06:19:59.643215 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.112s	user 0.086s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":155,"lbm_read_time_us":7603,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20406,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:19:59.643795 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=10.126437
I20260812 06:19:59.682686 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.039s	user 0.018s	sys 0.012s Metrics: {"bytes_written":12307494,"delete_count":0,"lbm_write_time_us":14099,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:59.683190 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=2.188937
I20260812 06:19:59.698040 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5276,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.698529 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=1.000000
I20260812 06:19:59.825302 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.127s	user 0.103s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672281,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":152,"lbm_read_time_us":10362,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21946,"lbm_writes_lt_1ms":443,"mutex_wait_us":31,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16000,"update_count":2000}
I20260812 06:19:59.825780 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=10.126437
I20260812 06:19:59.878297 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.052s	user 0.015s	sys 0.027s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15617,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:59.878798 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=2.188937
I20260812 06:19:59.888741 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3775,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.889139 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=1.000000
I20260812 06:20:00.030326 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.141s	user 0.096s	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":392,"lbm_read_time_us":10669,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20776,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2000}
I20260812 06:20:00.030925 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=10.126437
I20260812 06:20:00.070053 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.039s	user 0.026s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13749,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:00.070520 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=2.188937
I20260812 06:20:00.080994 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3850,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:00.081667 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=1.000000
I20260812 06:20:00.211489 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.130s	user 0.114s	sys 0.016s 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":833,"lbm_read_time_us":8979,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26474,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":2000}
I20260812 06:20:00.211980 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=10.126437
I20260812 06:20:00.252542 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.040s	user 0.027s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15307,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:00.253196 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=2.188937
I20260812 06:20:00.263407 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3777,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:00.263970 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushMRSOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=1.000000
I20260812 06:20:00.294736 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushMRSOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.031s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":193,"dirs.run_wall_time_us":1156,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1855,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:00.295393 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling LogGCOp(6991badf6bb54de684e5f2dfd10e4d83): free 112239259 bytes of WAL
I20260812 06:20:00.295645 13501 log_reader.cc:385] T 6991badf6bb54de684e5f2dfd10e4d83: removed 11 log segments from log reader
I20260812 06:20:00.295692 13501 log.cc:1079] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/6991badf6bb54de684e5f2dfd10e4d83/wal-000000003 (ops 12-16)
I20260812 06:20:00.295733 13501 log.cc:1079] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/6991badf6bb54de684e5f2dfd10e4d83/wal-000000004 (ops 17-21)
I20260812 06:20:00.295766 13501 log.cc:1079] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/6991badf6bb54de684e5f2dfd10e4d83/wal-000000005 (ops 22-26)
I20260812 06:20:00.295797 13501 log.cc:1079] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/6991badf6bb54de684e5f2dfd10e4d83/wal-000000006 (ops 27-31)
I20260812 06:20:00.295828 13501 log.cc:1079] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/6991badf6bb54de684e5f2dfd10e4d83/wal-000000007 (ops 32-36)
I20260812 06:20:00.295858 13501 log.cc:1079] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/6991badf6bb54de684e5f2dfd10e4d83/wal-000000008 (ops 37-41)
I20260812 06:20:00.295888 13501 log.cc:1079] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/6991badf6bb54de684e5f2dfd10e4d83/wal-000000009 (ops 42-46)
I20260812 06:20:00.295919 13501 log.cc:1079] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/6991badf6bb54de684e5f2dfd10e4d83/wal-000000010 (ops 47-51)
I20260812 06:20:00.295944 13501 log.cc:1079] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/6991badf6bb54de684e5f2dfd10e4d83/wal-000000011 (ops 52-56)
I20260812 06:20:00.295975 13501 log.cc:1079] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/6991badf6bb54de684e5f2dfd10e4d83/wal-000000012 (ops 57-60)
I20260812 06:20:00.296005 13501 log.cc:1079] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/6991badf6bb54de684e5f2dfd10e4d83/wal-000000013 (ops 61-65)
I20260812 06:20:00.315418 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: LogGCOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.020s	user 0.000s	sys 0.017s Metrics: {}
I20260812 06:20:00.315877 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=2.188937
I20260812 06:20:00.332685 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.017s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3823,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:00.333221 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling UndoDeltaBlockGCOp(6991badf6bb54de684e5f2dfd10e4d83): 446 bytes on disk
I20260812 06:20:00.333611 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: UndoDeltaBlockGCOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:20:00.334056 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=2.188937
I20260812 06:20:00.349045 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5346,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:00.349632 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=1.000000
I20260812 06:20:00.522961 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.173s	user 0.125s	sys 0.048s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877339,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":224,"lbm_read_time_us":13228,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33720,"lbm_writes_lt_1ms":643,"mutex_wait_us":23,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":16384,"thread_start_us":73,"threads_started":1,"update_count":3000}
I20260812 06:20:00.523499 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=14.095187
I20260812 06:20:00.569335 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.046s	user 0.022s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":17192,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:00.569842 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=2.188937
I20260812 06:20:00.580116 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3916,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:00.580641 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=1.000000
I20260812 06:20:00.733127 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.152s	user 0.099s	sys 0.046s 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":227,"lbm_read_time_us":10258,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27214,"lbm_writes_lt_1ms":543,"mutex_wait_us":19,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10240,"update_count":2500}
I20260812 06:20:00.733906 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=14.095187
I20260812 06:20:00.784040 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.050s	user 0.021s	sys 0.020s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20092,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:00.784629 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=1.000000
I20260812 06:20:00.935002 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.150s	user 0.087s	sys 0.060s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672156,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":420,"lbm_read_time_us":10159,"lbm_reads_lt_1ms":463,"lbm_write_time_us":23114,"lbm_writes_lt_1ms":443,"mutex_wait_us":363,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:20:00.935619 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=11.118625
I20260812 06:20:00.968173 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.032s	user 0.025s	sys 0.004s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13075,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:00.968688 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=2.188937
I20260812 06:20:00.982300 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4804,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:00.982813 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=1.000000
I20260812 06:20:01.102221 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.119s	user 0.089s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":818,"lbm_read_time_us":8976,"lbm_reads_lt_1ms":464,"lbm_write_time_us":20771,"lbm_writes_lt_1ms":443,"mutex_wait_us":261,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18304,"update_count":2000}
I20260812 06:20:01.102908 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=10.126437
I20260812 06:20:01.162235 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.059s	user 0.010s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":43461,"lbm_writes_1-10_ms":1,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:20:01.162835 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=2.188937
I20260812 06:20:01.181463 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.018s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4770,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.182055 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=1.000000
I20260812 06:20:01.304236 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.122s	user 0.097s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":652,"lbm_read_time_us":8968,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22908,"lbm_writes_lt_1ms":443,"mutex_wait_us":29,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":100096,"update_count":2000}
I20260812 06:20:01.304975 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=10.126437
I20260812 06:20:01.344648 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.039s	user 0.028s	sys 0.003s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13079,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:01.345172 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=2.188937
I20260812 06:20:01.355207 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3665,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.355744 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=1.000000
I20260812 06:20:01.480273 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.124s	user 0.088s	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":221,"lbm_read_time_us":8601,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23513,"lbm_writes_lt_1ms":443,"mutex_wait_us":49,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16384,"update_count":2000}
I20260812 06:20:01.481020 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=10.126437
I20260812 06:20:01.525936 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.045s	user 0.017s	sys 0.026s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15066,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:01.526623 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=2.188937
I20260812 06:20:01.541826 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.015s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102660,"delete_count":0,"lbm_write_time_us":5638,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.542433 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=1.000000
I20260812 06:20:01.679972 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.137s	user 0.091s	sys 0.045s 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":209,"lbm_read_time_us":10659,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21028,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":2000}
I20260812 06:20:01.680567 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=10.126437
I20260812 06:20:01.724293 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.043s	user 0.015s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16086,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:01.724839 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=2.188937
I20260812 06:20:01.739938 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.015s	user 0.012s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5586,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.740516 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushMRSOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=1.000000
I20260812 06:20:01.773736 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushMRSOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.033s	user 0.025s	sys 0.006s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":74,"dirs.run_cpu_time_us":246,"dirs.run_wall_time_us":1459,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1563,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:01.774412 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling LogGCOp(6991badf6bb54de684e5f2dfd10e4d83): free 133024419 bytes of WAL
I20260812 06:20:01.774629 13501 log_reader.cc:385] T 6991badf6bb54de684e5f2dfd10e4d83: removed 13 log segments from log reader
I20260812 06:20:01.774672 13501 log.cc:1079] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/6991badf6bb54de684e5f2dfd10e4d83/wal-000000014 (ops 66-70)
I20260812 06:20:01.774703 13501 log.cc:1079] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/6991badf6bb54de684e5f2dfd10e4d83/wal-000000015 (ops 71-75)
I20260812 06:20:01.774739 13501 log.cc:1079] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/6991badf6bb54de684e5f2dfd10e4d83/wal-000000016 (ops 76-80)
I20260812 06:20:01.774763 13501 log.cc:1079] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/6991badf6bb54de684e5f2dfd10e4d83/wal-000000017 (ops 81-85)
I20260812 06:20:01.774796 13501 log.cc:1079] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/6991badf6bb54de684e5f2dfd10e4d83/wal-000000018 (ops 86-90)
I20260812 06:20:01.774827 13501 log.cc:1079] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/6991badf6bb54de684e5f2dfd10e4d83/wal-000000019 (ops 91-95)
I20260812 06:20:01.774858 13501 log.cc:1079] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/6991badf6bb54de684e5f2dfd10e4d83/wal-000000020 (ops 96-100)
I20260812 06:20:01.774891 13501 log.cc:1079] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/6991badf6bb54de684e5f2dfd10e4d83/wal-000000021 (ops 101-104)
I20260812 06:20:01.774924 13501 log.cc:1079] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/6991badf6bb54de684e5f2dfd10e4d83/wal-000000022 (ops 105-109)
I20260812 06:20:01.774956 13501 log.cc:1079] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/6991badf6bb54de684e5f2dfd10e4d83/wal-000000023 (ops 110-114)
I20260812 06:20:01.774987 13501 log.cc:1079] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/6991badf6bb54de684e5f2dfd10e4d83/wal-000000024 (ops 115-119)
I20260812 06:20:01.775020 13501 log.cc:1079] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/6991badf6bb54de684e5f2dfd10e4d83/wal-000000025 (ops 120-124)
I20260812 06:20:01.775051 13501 log.cc:1079] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/6991badf6bb54de684e5f2dfd10e4d83/wal-000000026 (ops 125-129)
I20260812 06:20:01.799619 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: LogGCOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.025s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:20:01.800154 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=4.173312
I20260812 06:20:01.823947 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.024s	user 0.008s	sys 0.012s Metrics: {"bytes_written":6194894,"delete_count":0,"lbm_write_time_us":6884,"lbm_writes_lt_1ms":154,"reinsert_count":0,"update_count":755}
I20260812 06:20:01.824476 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=1.000000
I20260812 06:20:01.830451 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.006s	user 0.004s	sys 0.000s Metrics: {"bytes_written":2010377,"delete_count":0,"lbm_write_time_us":1800,"lbm_writes_lt_1ms":52,"reinsert_count":0,"update_count":245}
I20260812 06:20:01.830865 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=1.000000
I20260812 06:20:02.028759 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.198s	user 0.153s	sys 0.039s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877287,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":115,"lbm_read_time_us":13584,"lbm_reads_lt_1ms":674,"lbm_write_time_us":30949,"lbm_writes_lt_1ms":643,"mutex_wait_us":46,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":14080,"thread_start_us":73,"threads_started":1,"update_count":3000}
I20260812 06:20:02.029321 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling UndoDeltaBlockGCOp(6991badf6bb54de684e5f2dfd10e4d83): 483 bytes on disk
I20260812 06:20:02.029747 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: UndoDeltaBlockGCOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:20:02.030305 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=14.095187
I20260812 06:20:02.083563 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.053s	user 0.019s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":16452,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:02.084254 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=2.188937
I20260812 06:20:02.095239 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4146,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.095791 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=1.000000
I20260812 06:20:02.284363 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.188s	user 0.152s	sys 0.024s 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":1298,"lbm_read_time_us":13807,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26719,"lbm_writes_lt_1ms":543,"mutex_wait_us":266,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":384,"update_count":2500}
I20260812 06:20:02.284873 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=14.095187
I20260812 06:20:02.333457 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.048s	user 0.014s	sys 0.032s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20455,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:02.333911 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=2.188937
I20260812 06:20:02.345007 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4026,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.345746 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=1.000000
I20260812 06:20:02.521919 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.176s	user 0.090s	sys 0.069s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":573,"lbm_read_time_us":10763,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26097,"lbm_writes_lt_1ms":543,"mutex_wait_us":274,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2500}
I20260812 06:20:02.522456 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=14.095187
I20260812 06:20:02.571921 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.049s	user 0.022s	sys 0.017s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18561,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:02.572495 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=2.188937
I20260812 06:20:02.583647 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3958,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.584295 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=1.000000
I20260812 06:20:02.733004 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.148s	user 0.124s	sys 0.021s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":154,"lbm_read_time_us":9897,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27015,"lbm_writes_lt_1ms":543,"mutex_wait_us":46,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":60928,"update_count":2500}
I20260812 06:20:02.733628 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=11.118625
I20260812 06:20:02.769760 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.036s	user 0.027s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15132,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:02.770264 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=2.188937
I20260812 06:20:02.781479 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3954,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:02.781919 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=1.000000
I20260812 06:20:02.908640 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.127s	user 0.098s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":721,"lbm_read_time_us":7744,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23738,"lbm_writes_lt_1ms":443,"mutex_wait_us":312,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:20:02.909149 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=10.126437
I20260812 06:20:02.949510 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.040s	user 0.005s	sys 0.028s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14583,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:02.950073 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=2.188937
I20260812 06:20:02.964929 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.015s	user 0.002s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5254,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.965473 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=1.000000
I20260812 06:20:03.088204 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.123s	user 0.094s	sys 0.028s 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":1213,"lbm_read_time_us":7882,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22973,"lbm_writes_lt_1ms":443,"mutex_wait_us":311,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":2000}
I20260812 06:20:03.088809 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=10.126437
I20260812 06:20:03.136689 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.048s	user 0.025s	sys 0.023s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17874,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:03.137230 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=2.188937
I20260812 06:20:03.148130 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3937,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.148641 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushMRSOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=1.000000
I20260812 06:20:03.181768 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushMRSOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.033s	user 0.025s	sys 0.002s Metrics: {"bytes_written":1193505,"cfile_init":1,"dirs.queue_time_us":50,"dirs.run_cpu_time_us":175,"dirs.run_wall_time_us":1133,"drs_written":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1835,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:03.182452 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling LogGCOp(6991badf6bb54de684e5f2dfd10e4d83): free 112239510 bytes of WAL
I20260812 06:20:03.182662 13501 log_reader.cc:385] T 6991badf6bb54de684e5f2dfd10e4d83: removed 11 log segments from log reader
I20260812 06:20:03.182706 13501 log.cc:1079] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/6991badf6bb54de684e5f2dfd10e4d83/wal-000000027 (ops 130-134)
I20260812 06:20:03.182734 13501 log.cc:1079] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/6991badf6bb54de684e5f2dfd10e4d83/wal-000000028 (ops 135-139)
I20260812 06:20:03.182761 13501 log.cc:1079] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/6991badf6bb54de684e5f2dfd10e4d83/wal-000000029 (ops 140-144)
I20260812 06:20:03.182793 13501 log.cc:1079] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/6991badf6bb54de684e5f2dfd10e4d83/wal-000000030 (ops 145-148)
I20260812 06:20:03.182824 13501 log.cc:1079] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/6991badf6bb54de684e5f2dfd10e4d83/wal-000000031 (ops 149-153)
I20260812 06:20:03.182858 13501 log.cc:1079] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/6991badf6bb54de684e5f2dfd10e4d83/wal-000000032 (ops 154-158)
I20260812 06:20:03.182890 13501 log.cc:1079] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/6991badf6bb54de684e5f2dfd10e4d83/wal-000000033 (ops 159-162)
I20260812 06:20:03.182921 13501 log.cc:1079] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/6991badf6bb54de684e5f2dfd10e4d83/wal-000000034 (ops 163-167)
I20260812 06:20:03.182955 13501 log.cc:1079] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/6991badf6bb54de684e5f2dfd10e4d83/wal-000000035 (ops 168-173)
I20260812 06:20:03.182986 13501 log.cc:1079] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/6991badf6bb54de684e5f2dfd10e4d83/wal-000000036 (ops 174-178)
I20260812 06:20:03.183020 13501 log.cc:1079] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/6991badf6bb54de684e5f2dfd10e4d83/wal-000000037 (ops 179-183)
I20260812 06:20:03.201519 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: LogGCOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.019s	user 0.000s	sys 0.018s Metrics: {}
I20260812 06:20:03.201920 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling UndoDeltaBlockGCOp(6991badf6bb54de684e5f2dfd10e4d83): 462 bytes on disk
I20260812 06:20:03.202316 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: UndoDeltaBlockGCOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:20:03.202870 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=2.188937
I20260812 06:20:03.224578 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.022s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5189,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.225066 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling LogGCOp(6991badf6bb54de684e5f2dfd10e4d83): free 12018006 bytes of WAL
I20260812 06:20:03.225303 13501 log_reader.cc:385] T 6991badf6bb54de684e5f2dfd10e4d83: removed 1 log segments from log reader
I20260812 06:20:03.225350 13501 log.cc:1079] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: Deleting log segment in path: /tmp/dist-test-taskUFM9cI/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515593514226-12954-0/minicluster-data/ts-0-root/wals/6991badf6bb54de684e5f2dfd10e4d83/wal-000000038 (ops 184-188)
I20260812 06:20:03.227234 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: LogGCOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:20:03.227562 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=2.188937
I20260812 06:20:03.238282 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3579,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.238798 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=1.000000
I20260812 06:20:03.433514 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.195s	user 0.111s	sys 0.081s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877340,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":283,"lbm_read_time_us":14306,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31171,"lbm_writes_lt_1ms":643,"mutex_wait_us":30,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":35328,"thread_start_us":76,"threads_started":1,"update_count":3000}
I20260812 06:20:03.434046 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=14.095187
I20260812 06:20:03.476395 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.042s	user 0.029s	sys 0.013s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":17371,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:03.477190 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=2.188937
I20260812 06:20:03.489475 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: FlushDeltaMemStoresOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4534,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.489936 13621 maintenance_manager.cc:419] P a83e073df85048d6a54013fbd0a714b1: Scheduling MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83): perf score=1.000000
I20260812 06:20:03.509877 12954 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.650s	user 1.676s	sys 0.172s
I20260812 06:20:03.601073 12954 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.091s	user 0.003s	sys 0.000s
I20260812 06:20:03.601711 12954 tablet_server.cc:179] TabletServer@127.12.166.129:0 shutting down...
I20260812 06:20:03.657284 13501 maintenance_manager.cc:643] P a83e073df85048d6a54013fbd0a714b1: MajorDeltaCompactionOp(6991badf6bb54de684e5f2dfd10e4d83) complete. Timing: real 0.167s	user 0.111s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774693,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1012,"lbm_read_time_us":12672,"lbm_reads_lt_1ms":568,"lbm_write_time_us":29101,"lbm_writes_lt_1ms":543,"mutex_wait_us":281,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":40064,"update_count":2500}
I20260812 06:20:03.657893 12954 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:03.658138 12954 tablet_replica.cc:333] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1: stopping tablet replica
I20260812 06:20:03.658280 12954 raft_consensus.cc:2243] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:03.658432 12954 raft_consensus.cc:2272] T 6991badf6bb54de684e5f2dfd10e4d83 P a83e073df85048d6a54013fbd0a714b1 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:03.672897 12954 tablet_server.cc:196] TabletServer@127.12.166.129:0 shutdown complete.
I20260812 06:20:03.702132 12954 master.cc:562] Master@127.12.166.190:34081 shutting down...
I20260812 06:20:03.705154 12954 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 5bca116f36a74bd3b22c0cbbe752b148 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:03.705318 12954 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 5bca116f36a74bd3b22c0cbbe752b148 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:03.705371 12954 tablet_replica.cc:333] T 00000000000000000000000000000000 P 5bca116f36a74bd3b22c0cbbe752b148: stopping tablet replica
I20260812 06:20:03.717607 12954 master.cc:584] Master@127.12.166.190:34081 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5136 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10266 ms total)

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